Public bug reported: I have a routed provider network with 2 segments. Prior to creating an IPv6 subnet on a segment, I have created IPv4 subnets and attached a router to the external network without issue. When I attempt to create an IPv6 subnet on a segment, the following occurs:
> openstack subnet create --subnet-pool ULA --prefix-length 64 --network-segment 89254a60-1d84-4162-9d89-d678e8103594 --network c96b20c7-0702-4efa-a980-4e918979300a --ip-version 6 --no-dhcp RACK_1_ULA BadRequestException: 400: Client Error for url: http://controller:9696/v2.0/subnets, Invalid input for operation: Failed to create port on network c96b20c7-0702-4efa-a980-4e918979300a, because fixed_ips included invalid subnet 1237b25c-a357-40b2-9b5b-f311cd0bb075. Interestingly enough, the subnet was created despite this error. The subnet ID referenced in the error message is the UUID of the newly created subnet: > openstack subnet show 1237b25c-a357-40b2-9b5b-f311cd0bb075 +-------------------+-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+ | Field | Value | +-------------------+-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+ | allocation_pools | fd00::2-fd00::ffff:ffff:ffff:ffff | | cidr | fd00::/64 | | created_at | 2019-06-12T19:04:53Z | | description | | | dns_nameservers | | | enable_dhcp | False | | gateway_ip | fd00::1 | | host_routes | | | id | 1237b25c-a357-40b2-9b5b-f311cd0bb075 | | ip_version | 6 | | ipv6_address_mode | None | | ipv6_ra_mode | None | | location | Munch({'cloud': '', 'region_name': '', 'zone': None, 'project': Munch({'id': 'ea4d84a4ec2449a691eba8e9a664996a', 'name': 'admin', 'domain_id': 'default', 'domain_name': None})}) | | name | RACK_1_ULA | | network_id | c96b20c7-0702-4efa-a980-4e918979300a | | prefix_length | None | | project_id | ea4d84a4ec2449a691eba8e9a664996a | | revision_number | 0 | | segment_id | 89254a60-1d84-4162-9d89-d678e8103594 | | service_types | | | subnetpool_id | 08b4162a-8035-4296-8047-a4f3ed41be9b | | tags | | | updated_at | 2019-06-12T19:04:53Z | +-------------------+-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+ When I went to the logs (debug is enabled), another issue I found is that there is no stack trace or anything to indicate an error, other than the following from tracing the request ID: Jun 12 19:04:53 devstack-1 neutron-server[11973]: DEBUG neutron.api.v2.base [None req-742bf9e0-5f9c-42df-9f6f-991f3a56c9b6 admin admin] Request body: {'subnet': {'name': 'RACK_1_ULA', 'subnetpool_id': '08b4162a-8035-4296-8047-a4f3ed41be9b', 'ip_version': 6, 'prefixlen': '64', 'enable_dhcp': False, 'network_id': 'c96b20c7-0702-4efa-a980-4e918979300a', 'segment_id': '89254a60-1d84-4162-9d89-d678e8103594'}} {{(pid=11980) prepare_request_body /opt/stack/neutron/neutron/api/v2/base.py:715}} Jun 12 19:04:53 devstack-1 neutron-server[11973]: DEBUG neutron.db.quota.driver [None req-742bf9e0-5f9c-42df-9f6f-991f3a56c9b6 admin admin] Resources subnetpool have unlimited quota limit. It is not required to calculate headroom {{(pid=11980) make_reservation /opt/stack/neutron/neutron/db/quota/driver.py:222}} Jun 12 19:04:53 devstack-1 neutron-server[11973]: DEBUG neutron.quota.resource [None req-742bf9e0-5f9c-42df-9f6f-991f3a56c9b6 admin admin] Usage tracker for resource:subnet and tenant:ea4d84a4ec2449a691eba8e9a664996a is out of sync, need to count used quota {{(pid=11980) count_used /opt/stack/neutron/neutron/quota/resource.py:273}} Jun 12 19:04:53 devstack-1 neutron-server[11973]: DEBUG neutron.quota.resource [None req-742bf9e0-5f9c-42df-9f6f-991f3a56c9b6 admin admin] Quota usage for subnet was recalculated. Used quota:4. {{(pid=11980) count_used /opt/stack/neutron/neutron/quota/resource.py:293}} Jun 12 19:04:53 devstack-1 neutron-server[11973]: DEBUG neutron.db.quota.driver [None req-742bf9e0-5f9c-42df-9f6f-991f3a56c9b6 admin admin] Attempting to reserve 1 items for resource subnet. Total usage: 4; quota limit: 100; headroom:96 {{(pid=11980) make_reservation /opt/stack/neutron/neutron/db/quota/driver.py:254}} Jun 12 19:04:53 devstack-1 neutron-server[11973]: DEBUG neutron.pecan_wsgi.hooks.quota_enforcement [None req-742bf9e0-5f9c-42df-9f6f-991f3a56c9b6 admin admin] Made reservation on behalf of ea4d84a4ec2449a691eba8e9a664996a for: {'subnet': 1} {{(pid=11980) before /opt/stack/neutron/neutron/pecan_wsgi/hooks/quota_enforcement.py:55}} Jun 12 19:04:53 devstack-1 neutron-server[11973]: DEBUG neutron_lib.callbacks.manager [None req-742bf9e0-5f9c-42df-9f6f-991f3a56c9b6 admin admin] Notify callbacks ['neutron.services.segments.plugin.SegmentHostRoutes.host_routes_before_create--9223372036850996506'] for subnet, before_create {{(pid=11980) _notify_loop /usr/lib/python3.6/site-packages/neutron_lib/callbacks/manager.py:193}} Jun 12 19:04:54 devstack-1 neutron-server[11973]: DEBUG neutron_lib.callbacks.manager [None req-742bf9e0-5f9c-42df-9f6f-991f3a56c9b6 admin admin] Notify callbacks ['neutron.services.l3_router.l3_router_plugin.DVRResourceOperationHandler._handle_distributed_migration--9223372036850959293', 'neutron.services.l3_router.l3_router_plugin.L3_HA_NAT_db_mixin._validate_migration--9223372036851001076', 'neutron.services.l3_router.service_providers.driver_controller.DriverController._update_router_provider--9223372036854656083'] for router, precommit_update {{(pid=11980) _notify_loop /usr/lib/python3.6/site-packages/neutron_lib/callbacks/manager.py:193}} Jun 12 19:04:55 devstack-1 neutron-server[11973]: DEBUG neutron_lib.callbacks.manager [None req-742bf9e0-5f9c-42df-9f6f-991f3a56c9b6 admin admin] Notify callbacks ['neutron.plugins.ml2.plugin.SecurityGroupDbMixin._ensure_default_security_group_handler--9223372036830325123'] for port, before_update {{(pid=11980) _notify_loop /usr/lib/python3.6/site-packages/neutron_lib/callbacks/manager.py:193}} Jun 12 19:04:55 devstack-1 neutron-server[11973]: INFO neutron.pecan_wsgi.hooks.translation [None req-742bf9e0-5f9c-42df-9f6f-991f3a56c9b6 admin admin] POST failed (client error): The server could not comply with the request since it is either malformed or otherwise incorrect. Jun 12 19:04:55 devstack-1 neutron-server[11973]: DEBUG neutron.pecan_wsgi.hooks.notifier [None req-742bf9e0-5f9c-42df-9f6f-991f3a56c9b6 admin admin] No notification will be sent due to unsuccessful status code: 400 {{(pid=11980) after /opt/stack/neutron/neutron/pecan_wsgi/hooks/notifier.py:79}} Jun 12 19:04:55 devstack-1 neutron-server[11973]: INFO neutron.wsgi [None req-742bf9e0-5f9c-42df-9f6f-991f3a56c9b6 admin admin] 192.168.1.8 "POST /v2.0/subnets HTTP/1.1" status: 400 len: 458 time: 2.2952359 For some reason, the source of the malformed request error is not obvious. To summarize: - IPv6 subnet creation on an external network segment returns an error to the client, but the subnet gets created - The client alerts the user to a port creation failure due to having the newly created subnet passed in the 'fixed_ips' of the port create request (what port is even being created during a subnet create operation????) - The mysterious port creation transaction seems to think the newly created subnet is invalid, which leads me to believe there is an issue with DB transaction boundaries - The actual source of the error is hidden, even with debug enabled ** Affects: neutron Importance: Undecided Status: New -- You received this bug notification because you are a member of Yahoo! Engineering Team, which is subscribed to neutron. https://bugs.launchpad.net/bugs/1832636 Title: Error creating IPv6 subnet on routed network segment Status in neutron: New Bug description: I have a routed provider network with 2 segments. Prior to creating an IPv6 subnet on a segment, I have created IPv4 subnets and attached a router to the external network without issue. When I attempt to create an IPv6 subnet on a segment, the following occurs: > openstack subnet create --subnet-pool ULA --prefix-length 64 --network-segment 89254a60-1d84-4162-9d89-d678e8103594 --network c96b20c7-0702-4efa-a980-4e918979300a --ip-version 6 --no-dhcp RACK_1_ULA BadRequestException: 400: Client Error for url: http://controller:9696/v2.0/subnets, Invalid input for operation: Failed to create port on network c96b20c7-0702-4efa-a980-4e918979300a, because fixed_ips included invalid subnet 1237b25c-a357-40b2-9b5b- f311cd0bb075. Interestingly enough, the subnet was created despite this error. The subnet ID referenced in the error message is the UUID of the newly created subnet: > openstack subnet show 1237b25c-a357-40b2-9b5b-f311cd0bb075 +-------------------+-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+ | Field | Value | +-------------------+-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+ | allocation_pools | fd00::2-fd00::ffff:ffff:ffff:ffff | | cidr | fd00::/64 | | created_at | 2019-06-12T19:04:53Z | | description | | | dns_nameservers | | | enable_dhcp | False | | gateway_ip | fd00::1 | | host_routes | | | id | 1237b25c-a357-40b2-9b5b-f311cd0bb075 | | ip_version | 6 | | ipv6_address_mode | None | | ipv6_ra_mode | None | | location | Munch({'cloud': '', 'region_name': '', 'zone': None, 'project': Munch({'id': 'ea4d84a4ec2449a691eba8e9a664996a', 'name': 'admin', 'domain_id': 'default', 'domain_name': None})}) | | name | RACK_1_ULA | | network_id | c96b20c7-0702-4efa-a980-4e918979300a | | prefix_length | None | | project_id | ea4d84a4ec2449a691eba8e9a664996a | | revision_number | 0 | | segment_id | 89254a60-1d84-4162-9d89-d678e8103594 | | service_types | | | subnetpool_id | 08b4162a-8035-4296-8047-a4f3ed41be9b | | tags | | | updated_at | 2019-06-12T19:04:53Z | +-------------------+-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+ When I went to the logs (debug is enabled), another issue I found is that there is no stack trace or anything to indicate an error, other than the following from tracing the request ID: Jun 12 19:04:53 devstack-1 neutron-server[11973]: DEBUG neutron.api.v2.base [None req-742bf9e0-5f9c-42df-9f6f-991f3a56c9b6 admin admin] Request body: {'subnet': {'name': 'RACK_1_ULA', 'subnetpool_id': '08b4162a-8035-4296-8047-a4f3ed41be9b', 'ip_version': 6, 'prefixlen': '64', 'enable_dhcp': False, 'network_id': 'c96b20c7-0702-4efa-a980-4e918979300a', 'segment_id': '89254a60-1d84-4162-9d89-d678e8103594'}} {{(pid=11980) prepare_request_body /opt/stack/neutron/neutron/api/v2/base.py:715}} Jun 12 19:04:53 devstack-1 neutron-server[11973]: DEBUG neutron.db.quota.driver [None req-742bf9e0-5f9c-42df-9f6f-991f3a56c9b6 admin admin] Resources subnetpool have unlimited quota limit. It is not required to calculate headroom {{(pid=11980) make_reservation /opt/stack/neutron/neutron/db/quota/driver.py:222}} Jun 12 19:04:53 devstack-1 neutron-server[11973]: DEBUG neutron.quota.resource [None req-742bf9e0-5f9c-42df-9f6f-991f3a56c9b6 admin admin] Usage tracker for resource:subnet and tenant:ea4d84a4ec2449a691eba8e9a664996a is out of sync, need to count used quota {{(pid=11980) count_used /opt/stack/neutron/neutron/quota/resource.py:273}} Jun 12 19:04:53 devstack-1 neutron-server[11973]: DEBUG neutron.quota.resource [None req-742bf9e0-5f9c-42df-9f6f-991f3a56c9b6 admin admin] Quota usage for subnet was recalculated. Used quota:4. {{(pid=11980) count_used /opt/stack/neutron/neutron/quota/resource.py:293}} Jun 12 19:04:53 devstack-1 neutron-server[11973]: DEBUG neutron.db.quota.driver [None req-742bf9e0-5f9c-42df-9f6f-991f3a56c9b6 admin admin] Attempting to reserve 1 items for resource subnet. Total usage: 4; quota limit: 100; headroom:96 {{(pid=11980) make_reservation /opt/stack/neutron/neutron/db/quota/driver.py:254}} Jun 12 19:04:53 devstack-1 neutron-server[11973]: DEBUG neutron.pecan_wsgi.hooks.quota_enforcement [None req-742bf9e0-5f9c-42df-9f6f-991f3a56c9b6 admin admin] Made reservation on behalf of ea4d84a4ec2449a691eba8e9a664996a for: {'subnet': 1} {{(pid=11980) before /opt/stack/neutron/neutron/pecan_wsgi/hooks/quota_enforcement.py:55}} Jun 12 19:04:53 devstack-1 neutron-server[11973]: DEBUG neutron_lib.callbacks.manager [None req-742bf9e0-5f9c-42df-9f6f-991f3a56c9b6 admin admin] Notify callbacks ['neutron.services.segments.plugin.SegmentHostRoutes.host_routes_before_create--9223372036850996506'] for subnet, before_create {{(pid=11980) _notify_loop /usr/lib/python3.6/site-packages/neutron_lib/callbacks/manager.py:193}} Jun 12 19:04:54 devstack-1 neutron-server[11973]: DEBUG neutron_lib.callbacks.manager [None req-742bf9e0-5f9c-42df-9f6f-991f3a56c9b6 admin admin] Notify callbacks ['neutron.services.l3_router.l3_router_plugin.DVRResourceOperationHandler._handle_distributed_migration--9223372036850959293', 'neutron.services.l3_router.l3_router_plugin.L3_HA_NAT_db_mixin._validate_migration--9223372036851001076', 'neutron.services.l3_router.service_providers.driver_controller.DriverController._update_router_provider--9223372036854656083'] for router, precommit_update {{(pid=11980) _notify_loop /usr/lib/python3.6/site-packages/neutron_lib/callbacks/manager.py:193}} Jun 12 19:04:55 devstack-1 neutron-server[11973]: DEBUG neutron_lib.callbacks.manager [None req-742bf9e0-5f9c-42df-9f6f-991f3a56c9b6 admin admin] Notify callbacks ['neutron.plugins.ml2.plugin.SecurityGroupDbMixin._ensure_default_security_group_handler--9223372036830325123'] for port, before_update {{(pid=11980) _notify_loop /usr/lib/python3.6/site-packages/neutron_lib/callbacks/manager.py:193}} Jun 12 19:04:55 devstack-1 neutron-server[11973]: INFO neutron.pecan_wsgi.hooks.translation [None req-742bf9e0-5f9c-42df-9f6f-991f3a56c9b6 admin admin] POST failed (client error): The server could not comply with the request since it is either malformed or otherwise incorrect. Jun 12 19:04:55 devstack-1 neutron-server[11973]: DEBUG neutron.pecan_wsgi.hooks.notifier [None req-742bf9e0-5f9c-42df-9f6f-991f3a56c9b6 admin admin] No notification will be sent due to unsuccessful status code: 400 {{(pid=11980) after /opt/stack/neutron/neutron/pecan_wsgi/hooks/notifier.py:79}} Jun 12 19:04:55 devstack-1 neutron-server[11973]: INFO neutron.wsgi [None req-742bf9e0-5f9c-42df-9f6f-991f3a56c9b6 admin admin] 192.168.1.8 "POST /v2.0/subnets HTTP/1.1" status: 400 len: 458 time: 2.2952359 For some reason, the source of the malformed request error is not obvious. To summarize: - IPv6 subnet creation on an external network segment returns an error to the client, but the subnet gets created - The client alerts the user to a port creation failure due to having the newly created subnet passed in the 'fixed_ips' of the port create request (what port is even being created during a subnet create operation????) - The mysterious port creation transaction seems to think the newly created subnet is invalid, which leads me to believe there is an issue with DB transaction boundaries - The actual source of the error is hidden, even with debug enabled To manage notifications about this bug go to: https://bugs.launchpad.net/neutron/+bug/1832636/+subscriptions -- Mailing list: https://launchpad.net/~yahoo-eng-team Post to : yahoo-eng-team@lists.launchpad.net Unsubscribe : https://launchpad.net/~yahoo-eng-team More help : https://help.launchpad.net/ListHelp