Nova API fails with 500s when called with non-project-scoped keystone tokens

[Lance Bragstad]

Nova instances need to be owned by a project, so users always call the create server API with project-scoped tokens. Nova fetches the project_id from the token/context object used in the request for ownership of the instance.

Keystone supports other token scopes, which are mutually exclusive. For example, a context object translated from a system-scoped token does not have a project_id attribute. Similarly, a context object translated from a domain-scoped token does not have a project_id attribute.

When I use a system or domain-scoped token to create an instance nova reports a 500 because of request validation discrepancies between the API layer and preparing to write the instance reference to the database.

Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: DEBUG nova.network.neutron [None req-67275bda-f302-41ba-8c71-2443fcae8239 None domain-admin] validate_networks() for [('aeab41c8-19d2-4df1-b6fc-127d88fbb80b', None, None, None)] {{(pid=840738) validate_networks /opt/stack/nova/nova/network/neutron.py:2350}}
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: DEBUG nova.virt.hardware [None req-67275bda-f302-41ba-8c71-2443fcae8239 None domain-admin] Flavor limits 0:0:0 {{(pid=840738) get_cpu_topology_constraints /opt/stack/nova/nova/virt/hardware.py:344}}
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: DEBUG nova.virt.hardware [None req-67275bda-f302-41ba-8c71-2443fcae8239 None domain-admin] Image limits 0:0:0 {{(pid=840738) get_cpu_topology_constraints /opt/stack/nova/nova/virt/hardware.py:348}}
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: DEBUG nova.virt.hardware [None req-67275bda-f302-41ba-8c71-2443fcae8239 None domain-admin] Flavor pref 0:0:0 {{(pid=840738) get_cpu_topology_constraints /opt/stack/nova/nova/virt/hardware.py:384}}
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: DEBUG nova.virt.hardware [None req-67275bda-f302-41ba-8c71-2443fcae8239 None domain-admin] Image pref 0:0:0 {{(pid=840738) get_cpu_topology_constraints /opt/stack/nova/nova/virt/hardware.py:388}}
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: DEBUG nova.virt.hardware [None req-67275bda-f302-41ba-8c71-2443fcae8239 None domain-admin] Chose sockets=0, cores=0, threads=0; limits were sockets=65536, cores=65536, threads=65536 {{(pid=840738) get_cpu_topology_constraints /opt/stack/nova/nova/virt/hardware.py:426}}
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: DEBUG oslo_concurrency.lockutils [None req-67275bda-f302-41ba-8c71-2443fcae8239 None domain-admin] Lock "00000000-0000-0000-0000-000000000000" acquired by "nova.context.set_target_cell.<locals>.get_or_set_cached_cell_and_set_connections" :: waited 0.000s {{(pid=840738) inner /usr/local/lib/python3.8/dist-packages/oslo_concurrency/lockutils.py:355}}
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: DEBUG oslo_concurrency.lockutils [None req-67275bda-f302-41ba-8c71-2443fcae8239 None domain-admin] Lock "00000000-0000-0000-0000-000000000000" released by "nova.context.set_target_cell.<locals>.get_or_set_cached_cell_and_set_connections" :: held 0.001s {{(pid=840738) inner /usr/local/lib/python3.8/dist-packages/oslo_concurrency/lockutils.py:367}}
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: DEBUG oslo_concurrency.lockutils [None req-67275bda-f302-41ba-8c71-2443fcae8239 None domain-admin] Lock "b372b456-3d2f-4843-bffd-998157e3c20e" acquired by "nova.context.set_target_cell.<locals>.get_or_set_cached_cell_and_set_connections" :: waited 0.000s {{(pid=840738) inner /usr/local/lib/python3.8/dist-packages/oslo_concurrency/lockutils.py:355}}
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: DEBUG oslo_concurrency.lockutils [None req-67275bda-f302-41ba-8c71-2443fcae8239 None domain-admin] Lock "b372b456-3d2f-4843-bffd-998157e3c20e" released by "nova.context.set_target_cell.<locals>.get_or_set_cached_cell_and_set_connections" :: held 0.000s {{(pid=840738) inner /usr/local/lib/python3.8/dist-packages/oslo_concurrency/lockutils.py:367}}
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: DEBUG nova.quota [None req-67275bda-f302-41ba-8c71-2443fcae8239 None domain-admin] Getting quotas for project None. Resources: {'instances', 'cores', 'ram'} {{(pid=840738) _get_quotas /opt/stack/nova/nova/quota.py:387}}
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: DEBUG nova.quota [None req-67275bda-f302-41ba-8c71-2443fcae8239 None domain-admin] Getting quotas for user 79e7b713cce843d8ac1431584f94686c and project None. Resources: {'instances', 'cores', 'ram'} {{(pid=840738) _get_quotas /opt/stack/nova/nova/quota.py:377}}
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: DEBUG nova.compute.api [None req-67275bda-f302-41ba-8c71-2443fcae8239 None domain-admin] Going to run 1 instances... {{(pid=840738) _provision_instances /opt/stack/nova/nova/compute/api.py:1262}}
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: DEBUG nova.compute.api [None req-67275bda-f302-41ba-8c71-2443fcae8239 None domain-admin] [instance: 0575a94d-2c49-48f9-b27f-34c3516bb39e] block_device_mapping [BlockDeviceMapping(attachment_id=<?>,boot_index=0,connection_info=None,created_at=<?>,delete_on_termination=True,deleted=<?>,deleted_at=<?>,destination_type='local',device_name=None,device_type='disk',disk_bus=None,guest_format=None,id=<?>,image_id='03a4f6d2-25fb-49ad-85a6-c23aaf4ab54b',instance=<?>,instance_uuid=<?>,no_device=False,snapshot_id=None,source_type='image',tag=None,updated_at=<?>,uuid=<?>,volume_id=None,volume_size=None,volume_type=None)] {{(pid=840738) _bdm_validate_set_size_and_instance /opt/stack/nova/nova/compute/api.py:1663}}
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: ERROR nova.api.openstack.wsgi [None req-67275bda-f302-41ba-8c71-2443fcae8239 None domain-admin] Unexpected exception in API method: ValueError: Field `project_id' cannot be None
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: ERROR nova.api.openstack.wsgi Traceback (most recent call last):
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: ERROR nova.api.openstack.wsgi File "/opt/stack/nova/nova/api/openstack/wsgi.py", line 658, in wrapped
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: ERROR nova.api.openstack.wsgi return f(*args, **kwargs)
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: ERROR nova.api.openstack.wsgi File "/opt/stack/nova/nova/api/validation/__init__.py", line 110, in wrapper
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: ERROR nova.api.openstack.wsgi return func(*args, **kwargs)
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: ERROR nova.api.openstack.wsgi File "/opt/stack/nova/nova/api/validation/__init__.py", line 110, in wrapper
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: ERROR nova.api.openstack.wsgi return func(*args, **kwargs)
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: ERROR nova.api.openstack.wsgi File "/opt/stack/nova/nova/api/validation/__init__.py", line 110, in wrapper
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: ERROR nova.api.openstack.wsgi return func(*args, **kwargs)
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: ERROR nova.api.openstack.wsgi [Previous line repeated 9 more times]
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: ERROR nova.api.openstack.wsgi File "/opt/stack/nova/nova/api/openstack/compute/servers.py", line 689, in create
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: ERROR nova.api.openstack.wsgi (instances, resv_id) = self.compute_api.create(context,
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: ERROR nova.api.openstack.wsgi File "/opt/stack/nova/nova/compute/api.py", line 2030, in create
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: ERROR nova.api.openstack.wsgi return self._create_instance(
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: ERROR nova.api.openstack.wsgi File "/opt/stack/nova/nova/compute/api.py", line 1532, in _create_instance
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: ERROR nova.api.openstack.wsgi instances_to_build = self._provision_instances(
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: ERROR nova.api.openstack.wsgi File "/opt/stack/nova/nova/compute/api.py", line 1395, in _provision_instances
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: ERROR nova.api.openstack.wsgi self._cleanup_build_artifacts(None, instances_to_build)
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: ERROR nova.api.openstack.wsgi File "/usr/local/lib/python3.8/dist-packages/oslo_utils/excutils.py", line 227, in __exit__
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: ERROR nova.api.openstack.wsgi self.force_reraise()
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: ERROR nova.api.openstack.wsgi File "/usr/local/lib/python3.8/dist-packages/oslo_utils/excutils.py", line 200, in force_reraise
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: ERROR nova.api.openstack.wsgi raise self.value
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: ERROR nova.api.openstack.wsgi File "/opt/stack/nova/nova/compute/api.py", line 1328, in _provision_instances
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: ERROR nova.api.openstack.wsgi build_request = objects.BuildRequest(context,
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: ERROR nova.api.openstack.wsgi File "/usr/local/lib/python3.8/dist-packages/oslo_versionedobjects/base.py", line 307, in __init__
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: ERROR nova.api.openstack.wsgi setattr(self, key, kwargs[key])
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: ERROR nova.api.openstack.wsgi File "/usr/local/lib/python3.8/dist-packages/oslo_versionedobjects/base.py", line 72, in setter
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: ERROR nova.api.openstack.wsgi field_value = field.coerce(self, name, value)
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: ERROR nova.api.openstack.wsgi File "/usr/local/lib/python3.8/dist-packages/oslo_versionedobjects/fields.py", line 202, in coerce
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: ERROR nova.api.openstack.wsgi return self._null(obj, attr)
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: ERROR nova.api.openstack.wsgi File "/usr/local/lib/python3.8/dist-packages/oslo_versionedobjects/fields.py", line 180, in _null
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: ERROR nova.api.openstack.wsgi raise ValueError(_("Field `%s' cannot be None") % attr)
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: ERROR nova.api.openstack.wsgi ValueError: Field `project_id' cannot be None
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: ERROR nova.api.openstack.wsgi
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: INFO nova.api.openstack.wsgi [None req-67275bda-f302-41ba-8c71-2443fcae8239 None domain-admin] HTTP exception thrown: Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: <class 'ValueError'>
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: DEBUG nova.api.openstack.wsgi [None req-67275bda-f302-41ba-8c71-2443fcae8239 None domain-admin] Returning 500 to user: Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: <class 'ValueError'> {{(pid=840738) __call__ /opt/stack/nova/nova/api/openstack/wsgi.py:927}}
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: INFO nova.api.openstack.requestlog [None req-67275bda-f302-41ba-8c71-2443fcae8239 None domain-admin] 192.168.1.20 "POST /compute/v2.1/servers" status: 500 len: 184 microversion: 2.1 time: 0.535295
Mar 12 15:21:29 neutron-devstack <email address hidden>[840738]: [pid: 840738|app: 0|req: 35/68] 192.168.1.20 () {66 vars in 1261 bytes} [Fri Mar 12 15:21:29 2021] POST /compute/v2.1/servers => generated 184 bytes in 536 msecs (HTTP/1.1 500) 9 headers in 391 bytes (1 switches on core 0)

You can recreate this relatively easily with a fresh devstack (minimally configured) and a system-scoped token:

╭─ubuntu@neutron-devstack ~/devstack ‹f6c92b86*›
╰─➤ $ openstack --os-cloud devstack-system-admin server create --flavor m1.nano --image cirros-0.5.1-x86_64-disk --network aeab41c8-19d2-4df1-b6fc-127d88fbb80b foo
Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.
<class 'ValueError'> (HTTP 500) (Request-ID: req-67275bda-f302-41ba-8c71-2443fcae8239)

[Ghanshyam Mann (ghanshyammann)]

IRC discussion link, it is not yet concluded yet how to fix this or what is the best way of the usage of system scope for project's resources.

http://eavesdrop.openstack.org/irclogs/%23openstack-nova/%23openstack-nova.2021-03-12.log.html#t2021-03-12T15:33:36

[John Garbutt (johngarbutt)]

Sorry missed the discussion, but for me this is a bad request, 400.

If we want to allow the admin to provide a project id in a future microversion, sure, whatever, but it’s an edge case for me, and an action I see people turning off via policy. Actions on specific existing servers should work as normal, I presume?

[Sylvain Bauza (sylvain-bauza)]

Whatever we could do, this looks a bad bug to me and we should either provide a HTTP400 exception (in case we don't want to support those non-project scope tokens) or fixing this in the Nova API or in the context (I dunno).

Either way, providing a HTTP500 seems to me very bad so I'll accept this bug report but then we can continue to discuss about what to do here.