Failed test 'Launch instance with file injection'

[Dmitry Teselkin]

Job URL: https://ci.fuel-infra.org/job/11.0-community.main.ubuntu.bvt_2/226/
Snapshot URL: https://ci.fuel-infra.org/job/11.0-community.main.ubuntu.bvt_2/226/artifact/logs/fail_error_ceph_rados_gw-fuel-snapshot-2016-12-21_02-33-58.tar

Seems to be the same as https://bugs.launchpad.net/fuel/+bug/1651701

Failed test 'Launch instance with file injection'
-----
2016-12-21 02:32:35 FAILURE Launch instance with file injection (fuel_health.tests.smoke.test_nova_create_instance_with_connectivity.TestNovaNetwork.test_009_create_server_with_file) Floating IP can not be assigned. Please refer to OpenStack logs for more details. File "/usr/lib/python2.7/site-packages/unittest2/case.py", line 67, in testPartExecutor
    yield
  File "/usr/lib/python2.7/site-packages/unittest2/case.py", line 601, in run
    testMethod()
  File "/usr/lib/python2.7/site-packages/fuel_health/tests/smoke/test_nova_create_instance_with_connectivity.py", line 340, in test_009_create_server_with_file
    self.compute_client, server, floating_ip)
  File "/usr/lib/python2.7/site-packages/fuel_health/common/test_mixins.py", line 180, in verify
    " Please refer to OpenStack logs for more details.")
  File "/usr/lib/python2.7/site-packages/unittest2/case.py", line 666, in fail
    raise self.failureException(msg)
Step 3 failed: Floating IP can not be assigned. Please refer to OpenStack logs for more details.
-----

nova-api.log contains
-----
2016-12-21T02:32:35.349854+00:00 err: 2016-12-21 02:32:35.330 4524 ERROR nova.api.openstack.compute.floating_ips [req-f4acb6f6-bb3f-4a7a-b901-907a522f588d 18d7a418790047aa8a9fffe84e99ddff 0bf36b886c914246a1271ef79f1d56dd - default default] Unable to associate floating IP 10.109.24.131 to fixed IP 10.109.25.8 for instance 8f1a7de7-aec9-4ba0-b554-9ce6b2814598. Error: External network ab5f6e82-b1a9-454f-9c6d-db221a95f51a is not reachable from subnet f2b27ea2-371d-4654-92a8-064fd87bbec6. Therefore, cannot associate Port a46cb753-8fd6-47b4-b0e1-d9626e48df3f with a Floating IP.
Neutron server returns request_ids: ['req-438fbe7a-90d5-4b84-887c-fd76c25b6f20']
2016-12-21 02:32:35.330 4524 ERROR nova.api.openstack.compute.floating_ips Traceback (most recent call last):
2016-12-21 02:32:35.330 4524 ERROR nova.api.openstack.compute.floating_ips File "/usr/lib/python2.7/dist-packages/nova/api/openstack/compute/floating_ips.py", line 265, in _add_floating_ip
2016-12-21 02:32:35.330 4524 ERROR nova.api.openstack.compute.floating_ips fixed_address=fixed_address)
2016-12-21 02:32:35.330 4524 ERROR nova.api.openstack.compute.floating_ips File "/usr/lib/python2.7/dist-packages/nova/network/base_api.py", line 77, in wrapper
2016-12-21 02:32:35.330 4524 ERROR nova.api.openstack.compute.floating_ips res = f(self, context, *args, **kwargs)
2016-12-21 02:32:35.330 4524 ERROR nova.api.openstack.compute.floating_ips File "/usr/lib/python2.7/dist-packages/nova/network/neutronv2/api.py", line 1697, in associate_floating_ip
2016-12-21 02:32:35.330 4524 ERROR nova.api.openstack.compute.floating_ips client.update_floatingip(fip['id'], {'floatingip': param})
2016-12-21 02:32:35.330 4524 ERROR nova.api.openstack.compute.floating_ips File "/usr/lib/python2.7/dist-packages/nova/network/neutronv2/api.py", line 97, in wrapper
2016-12-21 02:32:35.330 4524 ERROR nova.api.openstack.compute.floating_ips ret = obj(*args, **kwargs)
2016-12-21 02:32:35.330 4524 ERROR nova.api.openstack.compute.floating_ips File "/usr/lib/python2.
2016-12-21T02:32:35.351016+00:00 info: 2016-12-21 02:32:35.349 4524 INFO nova.api.openstack.wsgi [req-f4acb6f6-bb3f-4a7a-b901-907a522f588d 18d7a418790047aa8a9fffe84e99ddff 0bf36b886c914246a1271ef79f1d56dd - default default] HTTP exception thrown: Unable to associate floating IP 10.109.24.131 to fixed IP 10.109.25.8 for instance 8f1a7de7-aec9-4ba0-b554-9ce6b2814598. Error: External network ab5f6e82-b1a9-454f-9c6d-db221a95f51a is not reachable from subnet f2b27ea2-371d-4654-92a8-064fd87bbec6. Therefore, cannot associate Port a46cb753-8fd6-47b4-b0e1-d9626e48df3f with a Floating IP.
Neutron server returns request_ids: ['req-438fbe7a-90d5-4b84-887c-fd76c25b6f20']
2016-12-21T02:32:35.353171+00:00 debug: 2016-12-21 02:32:35.352 4524 DEBUG nova.api.openstack.wsgi [req-f4acb6f6-bb3f-4a7a-b901-907a522f588d 18d7a418790047aa8a9fffe84e99ddff 0bf36b886c914246a1271ef79f1d56dd - default default] Returning 400 to user: Unable to associate floating IP 10.109.24.131 to fixed IP 10.109.25.8 for instance 8f1a7de7-aec9-4ba0-b554-9ce6b2814598. Error: External network ab5f6e82-b1a9-454f-9c6d-db221a95f51a is not reachable from subnet f2b27ea2-371d-4654-92a8-064fd87bbec6. Therefore, cannot associate Port a46cb753-8fd6-47b4-b0e1-d9626e48df3f with a Floating IP.
Neutron server returns request_ids: ['req-438fbe7a-90d5-4b84-887c-fd76c25b6f20'] __call__ /usr/lib/python2.7/dist-packages/nova/api/openstack/wsgi.py:1044
2016-12-21T02:32:35.363421+00:00 info: 2016-12-21 02:32:35.354 4524 INFO nova.osapi_compute.wsgi.server [req-f4acb6f6-bb3f-4a7a-b901-907a522f588d 18d7a418790047aa8a9fffe84e99ddff 0bf36b886c914246a1271ef79f1d56dd - default default] 10.109.22.9 "POST /v2.1/servers/8f1a7de7-aec9-4ba0-b554-9ce6b2814598/action HTTP/1.1" status: 400 len: 817 time: 0.4659081
-----

neutron-server.log contains
-----
2016-12-21T02:32:35.127987+00:00 debug: 2016-12-21 02:32:35.127 26581 DEBUG neutron.api.v2.base [req-438fbe7a-90d5-4b84-887c-fd76c25b6f20 18d7a418790047aa8a9fffe84e99ddff 0bf36b886c914246a1271ef79f1d56dd - - -] Request body: {u'floatingip': {u'fixed_ip_address': u'10.109.25.8', u'port_id': u'a46cb753-8fd6-47b4-b0e1-d9626e48df3f'}} prepare_request_body /usr/lib/python2.7/dist-packages/neutron/api/v2/base.py:655
2016-12-21T02:32:35.325179+00:00 info: 2016-12-21 02:32:35.324 26581 INFO neutron.api.v2.resource [req-438fbe7a-90d5-4b84-887c-fd76c25b6f20 18d7a418790047aa8a9fffe84e99ddff 0bf36b886c914246a1271ef79f1d56dd - - -] update failed (client error): The resource could not be found.
2016-12-21T02:32:35.336441+00:00 info: 2016-12-21 02:32:35.326 26581 INFO neutron.wsgi [req-438fbe7a-90d5-4b84-887c-fd76c25b6f20 18d7a418790047aa8a9fffe84e99ddff 0bf36b886c914246a1271ef79f1d56dd - - -] 10.109.22.9 - - [21/Dec/2016 02:32:35] "PUT /v2.0/floatingips/0f6b112f-d035-4aef-98a1-3dee20725f62.json HTTP/1.1" 404 522 0.203344
-----

[Nastya Urlapova (aurlapova)]

The similar issue is on version 10.0 #1163 case deploy_neutron_tun_ha:
Scenario:
            1. Create cluster
            2. Add 3 nodes with controller role
            3. Add 2 nodes with compute role
            4. Deploy the cluster
            5. Run network verification
>>> 6. Run OSTF <<< failed here

[Oleg Bondarev (obondarev)]

Error is "External network 4a12eaa6-e316-4317-bfd4-8914241b4b60 is not reachable from subnet 63801748-ec6f-4d59-9009-701864972ef0"

Indeed, by inspecting neutron server logs can see that test creates router with ext net as a gateway:

2016-12-29T00:53:46.414021+00:00 debug: 2016-12-29 00:53:46.413 28478 DEBUG neutron.api.v2.base [req-84cb8922-93ce-4110-8598-4217d0cc76a2 c37eae7145f0433eb185ce79d5fa3807 b006ba7e6b4f40919b498afb87f4d4af - - -] Request body: {u'router': {u'external_gateway_info': {u'network_id': u'4a12eaa6-e316-4317-bfd4-8914241b4b60', u'enable_snat': True}, u'tenant_id': u'b006ba7e6b4f40919b498afb87f4d4af', u'name': u'ost1_test-server-smoke-1759398823'}} prepare_request_body /usr/lib/python2.7/dist-packages/neutron/api/v2/base.py:684

Logically, subnet 63801748-ec6f-4d59-9009-701864972ef0 (where vm is booted later) should then be added to this router as an interface. However there is no such event in logs.
Can only see this subnet as an interface on another router (router04 created on deploy):

2016-12-28T23:53:18.868956+00:00 debug: 2016-12-28 23:53:18.870 27727 DEBUG neutron.db.l3_hamode_db [req-c4c56fc1-bf51-46b7-ba06-93520d981352 - - - - -] neutron.services.l3_router.l3_router_plugin.L3RouterPlugin method _process_sync_ha_data called with arguments (<neutron.context.Context object at 0x7f86aa581250>, [{'status': u'ACTIVE', '_interfaces': [{'status': u'DOWN', 'subnets': [{'dns_nameservers': [u'8.8.4.4', u'8.8.8.8'], 'ipv6_ra_mode': None, 'gateway_ip': u'10.109.4.1', 'cidr': u'10.109.4.0/24', 'id': u'63801748-ec6f-4d59-9009-701864972ef0', 'subnetpool_id': None}], 'dns_name': '', 'binding:host_id': u'', 'description': u'', 'allowed_address_pairs': [], 'extra_dhcp_opts': [], 'dns_assignment': [{'hostname': u'host-10-109-4-1', 'ip_address': u'10.109.4.1', 'fqdn': u'host-10-109-4-1.openstacklocal.'}], 'updated_at': '2016-12-28T23:52:49Z', 'device_owner': u'network:router_interface', 'revision_number': 5, 'port_security_enabled': False, 'binding:profile': {}, 'mtu': 1450, 'fixed_ips': [{'subnet_id': u'63801748-ec6f-4d59-9009-701864972ef0', 'prefixlen': 24, 'ip_address': u'10.109.4.1'}], 'id': u'b082f47f-5c08-4d92-88ca-e1a6b01d3e92', 'security_groups': [], 'device_id': u'f638d2c3-5a7b-461a-8b81-ccfceccb294a', 'name': u'', 'admin_state_up': True, 'network_id': u'e46663c3-4be2-48cc-9397-2ac79697cd51', 'tenant_id': u'b006ba7e6b4f40919b498afb87f4d4af', 'binding:vif_details': {}, 'address_scopes': {4: None, 6: None}, 'binding:vnic_type': u'normal', 'binding:vif_type': u'unbound', 'mac_address': u'fa:16:3e:2f:af:47', 'project_id': u'b006ba7e6b4f40919b498afb87f4d4af', 'extra_subnets': [], 'created_at': '2016-12-28T23:52:48Z'}], 'ha_vr_id': 0, 'description': u'', 'updated_at': '2016-12-28T23:52:48Z', 'revision_number': 3, 'ha': False, 'id': u'f638d2c3-5a7b-461a-8b81-ccfceccb294a', 'external_gateway_info': None, 'availability_zone_hints': [], 'availability_zones': [u'nova'], 'name': u'router04', 'gw_port_id': None, 'admin_state_up': True, 'tenant_id': u'b006ba7e6b4f40919b498afb87f4d4af', 'created_at': '2016-12-2

Out (test) router by the was has another subnet as an interface - e28c1450-7202-417b-ae20-8d90f5913479:

2016-12-29 00:53:54.6...

[Oleg Bondarev (obondarev)]

The jobs are green now, so I'll mark this as incomplete. Please reopen if the issue occurs again: will need to investigate the test scenario in that case.

[Oleg Bondarev (obondarev)]

sorry, not incomplete, but invalid