Open Stack

Hi,

If it fails only in some cases, it seems for me like maybe You have different
policy.json configured (or different neutron version installed) on controllers.
Can You check if all is the same in all cases?
Also please send logs from neutron-server from when this failed.

On Sun, Apr 19, 2020 at 02:08:09AM -0400, Laurent Dumont wrote:
> Hi!
> 
> I'm currently troubleshooting some transient Keystone/Neutron 403 issues
> when creating ports in RBAC-ed networks.
> 
>    - As part of our CI process,we are running a few sanity tests in virtual
>    Openstack setups with 3 controllers and 2 computes.
>    - One of those test validates the following scenarios (everything is
>    done through the Openstack python sdk) :
>       - Create projectA / UserA / ProjectB / UserB
>       - Create Network in project A
>       - RBAC Network in projectA to ProjectB
>       - With a token issued to a user in projectB, try to create the
>       following ports in project.
>          - regular port
>          - update regular port with a fixed IP
>          - update regular port with an allowed_address_pair
>          - create port with a fixed IP
>          - create port with an allowed address pair.
>       - The behavior that I'm seeing the most is that the port creation
>    will fail with the following error (the logs are from the sdk with
>    logging/debug enabled.
>    - It fails maybe 1/3 - and I'm unable to see a common pattern.
>    - This is testing against the same Openstack env and the
>    failures/success can happen within a few seconds of each others.
> 
> Sun Apr 19 01:54:06 2020 -- From ProjectB - create a port with a fixed
> > address in the network shared from ProjectA
> > REQ: curl -g -i -X GET
> > https://OPENSTACK_URL_HERE:13696/v2.0/subnets/77c3fad2-bf78-4b4e-bcfb-8114f95d7884
> > -H "User-Agent: openstacksdk/0.37.0 keystoneauth1/3.18.0
> > python-requests/2.22.0 CPython/3.7.5" -H "X-Auth-Token:
> > {SHA256}d80fe300742786033376f0591f98d3b4c342103cda1f802087809963694a7935"
> > RESP: [200] Content-Length: 619 Content-Type: application/json Date: Sun,
> > 19 Apr 2020 01:54:06 GMT X-Openstack-Request-Id:
> > req-fcee8345-7daa-499e-a985-92d59a31d0dd
> > RESP BODY:
> > {"subnet":{"service_types":[],"description":"","enable_dhcp":true,"tags":[],"network_id":"4ba08203-4328-418b-89e6-b82d474275d5","tenant_id":"472631dbfc5f4dfda9293fb93b5e493f","created_at":"2020-04-19T01:54:03Z","dns_nameservers":[],"updated_at":"2020-04-19T01:54:03Z","gateway_ip":"1.1.1.1","ipv6_ra_mode":null,"allocation_pools":[{"start":"1.1.1.2","end":"1.1.1.254"}],"host_routes":[],"revision_number":0,"ip_version":4,"ipv6_address_mode":null,"cidr":"
> > 1.1.1.0/24
> > ","project_id":"472631dbfc5f4dfda9293fb93b5e493f","id":"77c3fad2-bf78-4b4e-bcfb-8114f95d7884","subnetpool_id":null,"name":"neutronpolicy_shared_network"}}
> > GET call to network for
> > https://OPENSTACK_URL_HERE:13696/v2.0/subnets/77c3fad2-bf78-4b4e-bcfb-8114f95d7884
> > used request id req-fcee8345-7daa-499e-a985-92d59a31d0dd
> > REQ: curl -g -i -X POST https://OPENSTACK_URL_HERE:13696/v2.0/ports -H
> > "Content-Type: application/json" -H "User-Agent: openstacksdk/0.37.0
> > keystoneauth1/3.18.0 python-requests/2.22.0 CPython/3.7.5" -H
> > "X-Auth-Token:
> > {SHA256}d80fe300742786033376f0591f98d3b4c342103cda1f802087809963694a7935"
> > -d '{"port": {"name": "neutronpolicy_portb-fixed-ip", "network_id":
> > "4ba08203-4328-418b-89e6-b82d474275d5", "fixed_ips": [{"subnet_id":
> > "77c3fad2-bf78-4b4e-bcfb-8114f95d7884", "ip_address": "1.1.1.100"}]}}'
> > RESP: [403] Content-Length: 151 Content-Type: application/json Date: Sun,
> > 19 Apr 2020 01:54:07 GMT X-Openstack-Request-Id:
> > req-00277dbc-faca-479f-8736-563595d2729b
> > RESP BODY: {"NeutronError": {"message": "(rule:create_port and
> > rule:create_port:fixed_ips) is disallowed by policy", "type":
> > "PolicyNotAuthorized", "detail": ""}}
> > POST call to network for https://OPENSTACK_URL_HERE:13696/v2.0/ports used
> > request id req-00277dbc-faca-479f-8736-563595d2729b
> 
> 
> When it works, it looks the same, just without the 403 during the port
> creation.
> 
> Sun Apr 19 02:29:54 2020 -- From ProjectB - create a port with a fixed
> > address in the network shared from ProjectA
> > REQ: curl -g -i -X GET
> > https://OPENSTACK_URL_HERE:13696/v2.0/subnets/6d2231b6-3ce2-4121-a9a6-7284823c48ab
> > -H "User-Agent: openstacksdk/0.37.0 keystoneauth1/3.18.0
> > python-requests/2.22.0 CPython/3.7.5" -H "X-Auth-Token:
> > {SHA256}d39995434f6a0f106cae7408b07eee93846230f2bb5c922a8e16cfc7c8b26599"
> > RESP: [200] Content-Length: 619 Content-Type: application/json Date: Sun,
> > 19 Apr 2020 02:29:54 GMT X-Openstack-Request-Id:
> > req-bd41b51f-b6e9-454c-8c9a-ee444140459e
> > RESP BODY:
> > {"subnet":{"service_types":[],"description":"","enable_dhcp":true,"tags":[],"network_id":"e0d7e7a1-2863-45ec-bd7b-1767a1d02822","tenant_id":"4530b70143ec4cd0ad929a4ca571bdd8","created_at":"2020-04-19T02:29:51Z","dns_nameservers":[],"updated_at":"2020-04-19T02:29:51Z","gateway_ip":"1.1.1.1","ipv6_ra_mode":null,"allocation_pools":[{"start":"1.1.1.2","end":"1.1.1.254"}],"host_routes":[],"revision_number":0,"ip_version":4,"ipv6_address_mode":null,"cidr":"
> > 1.1.1.0/24
> > ","project_id":"4530b70143ec4cd0ad929a4ca571bdd8","id":"6d2231b6-3ce2-4121-a9a6-7284823c48ab","subnetpool_id":null,"name":"neutronpolicy_shared_network"}}
> > GET call to network for
> > https:/OPENSTACK_URL_HERE:13696/v2.0/subnets/6d2231b6-3ce2-4121-a9a6-7284823c48ab
> > used request id req-bd41b51f-b6e9-454c-8c9a-ee444140459e
> > REQ: curl -g -i -X POST https://OPENSTACK_URL_HERE:13696/v2.0/ports -H
> > "Content-Type: application/json" -H "User-Agent: openstacksdk/0.37.0
> > keystoneauth1/3.18.0 python-requests/2.22.0 CPython/3.7.5" -H
> > "X-Auth-Token:
> > {SHA256}d39995434f6a0f106cae7408b07eee93846230f2bb5c922a8e16cfc7c8b26599"
> > -d '{"port": {"name": "neutronpolicy_portb-fixed-ip", "network_id":
> > "e0d7e7a1-2863-45ec-bd7b-1767a1d02822", "fixed_ips": [{"subnet_id":
> > "6d2231b6-3ce2-4121-a9a6-7284823c48ab", "ip_address": "1.1.1.100"}]}}'
> > RESP: [201] Content-Length: 769 Content-Type: application/json Date: Sun,
> > 19 Apr 2020 02:29:56 GMT X-Openstack-Request-Id:
> > req-898dadfb-366d-4a78-8e89-c9d5e9a512f6
> > RESP BODY:
> > {"port":{"allowed_address_pairs":[],"extra_dhcp_opts":[],"updated_at":"2020-04-19T02:29:55Z","device_owner":"","revision_number":6,"port_security_enabled":true,"fixed_ips":[{"subnet_id":"6d2231b6-3ce2-4121-a9a6-7284823c48ab","ip_address":"1.1.1.100"}],"id":"9999784b-c38d-4cf2-b951-e8255d3483f4","security_groups":["4c022e69-b575-435b-bfb7-9cc81f50d49e"],"mac_address":"fa:16:3e:3e:22:fb","device_id":"","status":"DOWN","description":"","tags":[],"name":"neutronpolicy_portb-fixed-ip","project_id":"253ee9b6b5964185ab0818580129c011","qos_policy_id":null,"admin_state_up":true,"network_id":"e0d7e7a1-2863-45ec-bd7b-1767a1d02822","tenant_id":"253ee9b6b5964185ab0818580129c011","created_at":"2020-04-19T02:29:55Z","binding:vnic_type":"normal","ip_allocation":"immediate"}}
> > POST call to network for https://OPENSTACK_URL_HERE:13696/v2.0/ports used
> > request id req-898dadfb-366d-4a78-8e89-c9d5e9a512f6
> > Sun Apr 19 02:29:56 2020 -- PORT-OK
> 
> 
> This is what I see in the Neutron server logs (with debug enabled)
> 
> DEBUG neutron.api.v2.base [req-00277dbc-faca-479f-8736-563595d2729b
> > c905a7d0011e4bb4ae388cfd699e5989 4bae655884b44e8e9c8dbb5983fb3cd8 - default
> > default] Request body: {u'port': {u'network_id':
> > u'4ba08203-4328-418b-89e6-b82d474275d5', u'fixed_ips': [{u'subnet_id':
> > u'77c3fad2-bf78-4b4e-bcfb-8114f95d7884', u'ip_address': u'1.1.1.100'}],
> > u'name': u'neutronpolicy_portb-fixed-ip'}} prepare_request_body
> > /usr/lib/python2.7/site-packages/neutron/api/v2/base.py:690
> > DEBUG neutron.db.quota.driver [req-00277dbc-faca-479f-8736-563595d2729b
> > c905a7d0011e4bb4ae388cfd699e5989 4bae655884b44e8e9c8dbb5983fb3cd8 - default
> > default] Resources subnetpool,trunk have unlimited quota limit. It is not
> > required to calculate headroom  make_reservation
> > /usr/lib/python2.7/site-packages/neutron/db/quota/driver.py:223
> > DEBUG neutron.quota.resource [req-00277dbc-faca-479f-8736-563595d2729b
> > c905a7d0011e4bb4ae388cfd699e5989 4bae655884b44e8e9c8dbb5983fb3cd8 - default
> > default] Usage tracker for resource:port and
> > tenant:4bae655884b44e8e9c8dbb5983fb3cd8 is out of sync, need to count used
> > quota count_used
> > /usr/lib/python2.7/site-packages/neutron/quota/resource.py:272
> > DEBUG neutron.quota.resource [req-00277dbc-faca-479f-8736-563595d2729b
> > c905a7d0011e4bb4ae388cfd699e5989 4bae655884b44e8e9c8dbb5983fb3cd8 - default
> > default] Quota usage for port was recalculated. Used quota:0. count_used
> > /usr/lib/python2.7/site-packages/neutron/quota/resource.py:292
> > DEBUG neutron.db.quota.driver [req-00277dbc-faca-479f-8736-563595d2729b
> > c905a7d0011e4bb4ae388cfd699e5989 4bae655884b44e8e9c8dbb5983fb3cd8 - default
> > default] Attempting to reserve 1 items for resource port. Total usage: 0;
> > quota limit: 500; headroom:500 make_reservation
> > /usr/lib/python2.7/site-packages/neutron/db/quota/driver.py:255
> > DEBUG neutron.pecan_wsgi.hooks.quota_enforcement
> > [req-00277dbc-faca-479f-8736-563595d2729b c905a7d0011e4bb4ae388cfd699e5989
> > 4bae655884b44e8e9c8dbb5983fb3cd8 - default default] Made reservation on
> > behalf of 4bae655884b44e8e9c8dbb5983fb3cd8 for: {'port': 1} before
> > /usr/lib/python2.7/site-packages/neutron/pecan_wsgi/hooks/quota_enforcement.py:55
> > DEBUG neutron.policy [req-00277dbc-faca-479f-8736-563595d2729b
> > c905a7d0011e4bb4ae388cfd699e5989 4bae655884b44e8e9c8dbb5983fb3cd8 - default
> > default] Unable to find requested field: shared in target:
> > {'binding:host_id': <neutron_lib.constants.Sentinel object at
> > 0x7f2a3b214d50>, u'name': u'neutronpolicy_portb-fixed-ip',
> > 'allowed_address_pairs': <neutron_lib.constants.Sentinel object at
> > 0x7f2a3b214d50>, 'admin_state_up': True, u'network_id':
> > u'4ba08203-4328-418b-89e6-b82d474275d5', 'tenant_id':
> > u'4bae655884b44e8e9c8dbb5983fb3cd8', 'extra_dhcp_opts': None,
> > 'mac_address': <neutron_lib.constants.Sentinel object at 0x7f2a3b214d50>,
> > 'binding:vnic_type': 'normal', 'device_owner': '', 'qos_policy_id': None,
> > 'device_id': '', 'binding:profile': <neutron_lib.constants.Sentinel object
> > at 0x7f2a3b214d50>, 'port_security_enabled':
> > <neutron_lib.constants.Sentinel object at 0x7f2a3b214d50>, 'project_id':
> > u'4bae655884b44e8e9c8dbb5983fb3cd8', u'fixed_ips': [{u'subnet_id':
> > u'77c3fad2-bf78-4b4e-bcfb-8114f95d7884', u'ip_address': u'1.1.1.100'}],
> > u'network:tenant_id': u'472631dbfc5f4dfda9293fb93b5e493f',
> > 'security_groups': <neutron_lib.constants.Sentinel object at
> > 0x7f2a3b214d50>, 'description': ''} __call__
> > /usr/lib/python2.7/site-packages/neutron/policy.py:314
> > DEBUG neutron.policy [req-00277dbc-faca-479f-8736-563595d2729b
> > c905a7d0011e4bb4ae388cfd699e5989 4bae655884b44e8e9c8dbb5983fb3cd8 - default
> > default] Enforcing rules: ['create_port', 'create_port:fixed_ips']
> > log_rule_list /usr/lib/python2.7/site-packages/neutron/policy.py:334
> > DEBUG neutron.policy [req-00277dbc-faca-479f-8736-563595d2729b
> > c905a7d0011e4bb4ae388cfd699e5989 4bae655884b44e8e9c8dbb5983fb3cd8 - default
> > default] Failed policy check for 'create_port' enforce
> > /usr/lib/python2.7/site-packages/neutron/policy.py:405
> > INFO neutron.pecan_wsgi.hooks.translation
> > [req-00277dbc-faca-479f-8736-563595d2729b c905a7d0011e4bb4ae388cfd699e5989
> > 4bae655884b44e8e9c8dbb5983fb3cd8 - default default] POST failed (client
> > error): Access was denied to this resource.
> > DEBUG neutron.pecan_wsgi.hooks.notifier
> > [req-00277dbc-faca-479f-8736-563595d2729b c905a7d0011e4bb4ae388cfd699e5989
> > 4bae655884b44e8e9c8dbb5983fb3cd8 - default default] No notification will be
> > sent due to unsuccessful status code: 403 after
> > /usr/lib/python2.7/site-packages/neutron/pecan_wsgi/hooks/notifier.py:79
> > INFO neutron.wsgi [req-00277dbc-faca-479f-8736-563595d2729b
> > c905a7d0011e4bb4ae388cfd699e5989 4bae655884b44e8e9c8dbb5983fb3cd8 - default
> > default] 192.168.20.29 "POST /v2.0/ports HTTP/1.1" status: 403  len: 333
> > time: 0.3625510
> >
> 
> 
> I haven't found a whole lot online - just a couple of possibly related bugs
> https://bugs.launchpad.net/neutron/+bug/1808112
> https://bugzilla.redhat.com/show_bug.cgi?id=1683385
> 
> Does anyone have any good tips/debugging methods?
> 
> Thanks!

-- 
Slawek Kaplonski
Senior software engineer
Red Hat