Heat couldn't create instance, nova returned No valid host was found

[Egor Kotko]

Scenario:
1. Create new environment
2. Choose Neutron, TUN
3. Choose Ceph for volumes and Ceph for images
4. Choose Ceph RadosGW for objects
5. Choose Ceilometer
6. Add 3 controller+ceph
7. Add 1 compute
8. Add 2 ceph
9. Add 3 mongo
10. Change disk configuration for both Mongo nodes. Change 'MongoDB' volume for vdc
11. Verify networks
12. Deploy the environment
13. Verify networks
14. Run OSTF tests

OSTF failed on:
Update stack actions: inplace, replace and update whole template
Time limit exceeded while waiting for stack creation to finish. Please refer to OpenStack logs for more details.
Target component: Heat

Scenario:
1. Create test flavor.
2. Create a stack.

OSTF error log:
http://paste.openstack.org/show/418118/

heat-engine.log(node-5)
http://paste.openstack.org/show/418117/

{"build_id": "2015-08-12_15-16-47", "build_number": "164", "release_versions": {"2015.1.0-7.0": {"VERSION": {"build_id": "2015-08-12_15-16-47", "build_number": "164", "api": "1.0", "fuel-library_sha": "22f848670e49d89fc04aaed4d8efd1b07360cbe7", "nailgun_sha": "fff6bda090fac15c48b27cca7832a70f8e381101", "feature_groups": ["mirantis"], "fuel-nailgun-agent_sha": "e01693992d7a0304d926b922b43f3b747c35964c", "openstack_version": "2015.1.0-7.0", "fuel-agent_sha": "57145b1d8804389304cd04322ba0fb3dc9d30327", "production": "docker", "python-fuelclient_sha": "26fc025e0fc5791b62e5ed8561a6016bf8a406bc", "astute_sha": "e1d3a435e5df5b40cbfb1a3acf80b4176d15a2dc", "fuel-ostf_sha": "58220583f10fa47f12291488ef77854809c68310", "release": "7.0", "fuelmain_sha": "67e5214c0dc5d4ba6da4ae651cef9934800459a9"}}}, "auth_required": true, "api": "1.0", "fuel-library_sha": "22f848670e49d89fc04aaed4d8efd1b07360cbe7", "nailgun_sha": "fff6bda090fac15c48b27cca7832a70f8e381101", "feature_groups": ["mirantis"], "fuel-nailgun-agent_sha": "e01693992d7a0304d926b922b43f3b747c35964c", "openstack_version": "2015.1.0-7.0", "fuel-agent_sha": "57145b1d8804389304cd04322ba0fb3dc9d30327", "production": "docker", "python-fuelclient_sha": "26fc025e0fc5791b62e5ed8561a6016bf8a406bc", "astute_sha": "e1d3a435e5df5b40cbfb1a3acf80b4176d15a2dc", "fuel-ostf_sha": "58220583f10fa47f12291488ef77854809c68310", "release": "7.0", "fuelmain_sha": "67e5214c0dc5d4ba6da4ae651cef9934800459a9"}

Logs:
https://drive.google.com/a/mirantis.com/file/d/0BzWDM1PONYEuaUllczFpQmNrUms/view?usp=sharing

[Anastasia Kuznetsova (akuznetsova)]

Heat couldn't create stack, because creation of Server resource failed.
2015-08-16T16:00:12.976622+00:00 info: 2015-08-16 16:00:13.050 15635 INFO heat.engine.resource [-] CREATE: Server "Server" [971110b7-0d23-4fcf-8f3f-1971b94d2ed5] Stack "ost1_test-heat-stack-1520491900" [e195c6e1-6aa5-437b-9217-0efbe130abe9]
2015-08-16 16:00:13.050 15635 TRACE heat.engine.resource Traceback (most recent call last):
2015-08-16 16:00:13.050 15635 TRACE heat.engine.resource File "/usr/lib/python2.7/dist-packages/heat/engine/resource.py", line 500, in _action_recorder
2015-08-16 16:00:13.050 15635 TRACE heat.engine.resource yield
2015-08-16 16:00:13.050 15635 TRACE heat.engine.resource File "/usr/lib/python2.7/dist-packages/heat/engine/resource.py", line 570, in _do_action
2015-08-16 16:00:13.050 15635 TRACE heat.engine.resource yield self.action_handler_task(action, args=handler_args)
2015-08-16 16:00:13.050 15635 TRACE heat.engine.resource File "/usr/lib/python2.7/dist-packages/heat/engine/scheduler.py", line 313, in wrapper
2015-08-16 16:00:13.050 15635 TRACE heat.engine.resource step = next(subtask)
2015-08-16 16:00:13.050 15635 TRACE heat.engine.resource File "/usr/lib/python2.7/dist-packages/heat/engine/resource.py", line 544, in action_handler_task
2015-08-16 16:00:13.050 15635 TRACE heat.engine.resource while not check(handler_data):
2015-08-16 16:00:13.050 15635 TRACE heat.engine.resource File "/usr/lib/python2.7/dist-packages/heat/engine/resources/openstack/nova/server.py", line 704, in check_create_complete
2015-08-16 16:00:13.050 15635 TRACE heat.engine.resource return self._check_active(server)
2015-08-16 16:00:13.050 15635 TRACE heat.engine.resource File "/usr/lib/python2.7/dist-packages/heat/engine/resources/openstack/nova/server.py", line 723, in _check_active
2015-08-16 16:00:13.050 15635 TRACE heat.engine.resource 'code': fault.get('code', _('Unknown'))
2015-08-16 16:00:13.050 15635 TRACE heat.engine.resource ResourceInError: Went to status ERROR due to "Message: No valid host was found. There are not enough hosts available., Code: 500"
2015-08-16 16:00:13.050 15635 TRACE heat.engine.resource

Nova returns 500 code.

NOTE: there is no messages in nova-compute logs about this instance creation, so 500 code was returned not by nova-compute

[Roman Podoliaka (rpodolyaka)]

It didn't get to nova-compute node, but failed on the scheduling stage:

rpodolyaka@rpodolyaka-pc:~/Downloads/snapshots/var/log/docker-logs/remote$ grep 'returned 0 host' . -R
./10.109.10.7/nova-scheduler.log:2015-08-16T16:00:59.817049+00:00 info: 2015-08-16 16:00:59.978 29278 INFO nova.filters [req-4e65a88d-26fc-4513-924a-e742726fd5d4 bafb114ec61b48fc965c22a0f579fc4e fa6ada39b9c1465982ed41b027457ffe - - -] Filter RamFilter returned 0 hosts
./node-6.test.domain.local/nova-scheduler.log:2015-08-16T16:00:03.878868+00:00 info: 2015-08-16 16:00:03.949 26163 INFO nova.filters [req-2cf5e8db-2ba0-4d3c-862c-b1e25cd5e478 bafb114ec61b48fc965c22a0f579fc4e fa6ada39b9c1465982ed41b027457ffe - - -] Filter RamFilter returned 0 hosts
./node-6.test.domain.local/nova-scheduler.log:2015-08-16T16:02:22.655326+00:00 info: 2015-08-16 16:02:22.746 26163 INFO nova.filters [req-78974b8d-3adc-43f1-8528-5f44d00f7088 bafb114ec61b48fc965c22a0f579fc4e fa6ada39b9c1465982ed41b027457ffe - - -] Filter RamFilter returned 0 hosts
./node-5.test.domain.local/nova-scheduler.log:2015-08-16T15:27:29.216132+00:00 info: 2015-08-16 15:27:29.197 18430 INFO nova.filters [req-2bbb2dca-dfc7-48e5-b7cd-489523a15148 bafb114ec61b48fc965c22a0f579fc4e fa6ada39b9c1465982ed41b027457ffe - - -] Filter RetryFilter returned 0 hosts
./node-5.test.domain.local/nova-scheduler.log:2015-08-16T16:01:37.442845+00:00 info: 2015-08-16 16:01:37.414 18430 INFO nova.filters [req-14dd9b04-4d1b-4c24-a19c-b01279a4e200 bafb114ec61b48fc965c22a0f579fc4e fa6ada39b9c1465982ed41b027457ffe - - -] Filter RamFilter returned 0 hosts
./node-5.test.domain.local/nova-scheduler.log:2015-08-16T16:05:49.338705+00:00 info: 2015-08-16 16:05:49.307 18430 INFO nova.filters [req-4a7f8f4c-2a41-4adc-8e41-b7e5e6a4aa68 bafb114ec61b48fc965c22a0f579fc4e fa6ada39b9c1465982ed41b027457ffe - - -] Filter RetryFilter returned 0 hosts
./10.109.10.11/nova-scheduler.log:2015-08-16T16:00:03.878868+00:00 info: 2015-08-16 16:00:03.949 26163 INFO nova.filters [req-2cf5e8db-2ba0-4d3c-862c-b1e25cd5e478 bafb114ec61b48fc965c22a0f579fc4e fa6ada39b9c1465982ed41b027457ffe - - -] Filter RamFilter returned 0 hosts
./10.109.10.11/nova-scheduler.log:2015-08-16T16:02:22.655326+00:00 info: 2015-08-16 16:02:22.746 26163 INFO nova.filters [req-78974b8d-3adc-43f1-8528-5f44d00f7088 bafb114ec61b48fc965c22a0f579fc4e fa6ada39b9c1465982ed41b027457ffe - - -] Filter RamFilter returned 0 hosts
./10.109.10.10/nova-scheduler.log:2015-08-16T15:27:29.216132+00:00 info: 2015-08-16 15:27:29.197 18430 INFO nova.filters [req-2bbb2dca-dfc7-48e5-b7cd-489523a15148 bafb114ec61b48fc965c22a0f579fc4e fa6ada39b9c1465982ed41b027457ffe - - -] Filter RetryFilter returned 0 hosts
./10.109.10.10/nova-scheduler.log:2015-08-16T16:01:37.442845+00:00 info: 2015-08-16 16:01:37.414 18430 INFO nova.filters [req-14dd9b04-4d1b-4c24-a19c-b01279a4e200 bafb114ec61b48fc965c22a0f579fc4e fa6ada39b9c1465982ed41b027457ffe - - -] Filter RamFilter returned 0 hosts
./10.109.10.10/nova-scheduler.log:2015-08-16T16:05:49.338705+00:00 info: 2015-08-16 16:05:49.307 18430 INFO nova.filters [req-4a7f8f4c-2a41-4adc-8e41-b7e5e6a4aa68 bafb114ec61b48fc965c22a0f579fc4e fa6ada39b9c1465982ed41b027457ffe - - -] Filter Retry...

[Roman Podoliaka (rpodolyaka)]

I was going to mark the bug as Invalid, but we should fix the test/env to make sure this won't happen again. Thus, re-assigning back to Egor.

[Timur Nurlygayanov (tnurlygayanov)]

So, in this case bug status changed to Incomplete, since it is not bug in product.

Egor, please, fix the environment and set the correct status for this bug.

Thank you!

[Egor Kotko (ykotko)]

Was not reproduced on :
{"build_id": "288", "build_number": "288", "release_versions": {"2015.1.0-7.0": {"VERSION": {"build_id": "288", "build_number": "288", "api": "1.0", "fuel-library_sha": "121016a09b0e889994118aa3ea42fa67eabb8f25", "nailgun_sha": "93477f9b42c5a5e0506248659f40bebc9ac23943", "feature_groups": ["mirantis"], "fuel-nailgun-agent_sha": "d7027952870a35db8dc52f185bb1158cdd3d1ebd", "openstack_version": "2015.1.0-7.0", "fuel-agent_sha": "082a47bf014002e515001be05f99040437281a2d", "production": "docker", "python-fuelclient_sha": "1ce8ecd8beb640f2f62f73435f4e18d1469979ac", "astute_sha": "a717657232721a7fafc67ff5e1c696c9dbeb0b95", "fuel-ostf_sha": "1f08e6e71021179b9881a824d9c999957fcc7045", "release": "7.0", "fuelmain_sha": "6b83d6a6a75bf7bca3177fcf63b2eebbf1ad0a85"}}}, "auth_required": true, "api": "1.0", "fuel-library_sha": "121016a09b0e889994118aa3ea42fa67eabb8f25", "nailgun_sha": "93477f9b42c5a5e0506248659f40bebc9ac23943", "feature_groups": ["mirantis"], "fuel-nailgun-agent_sha": "d7027952870a35db8dc52f185bb1158cdd3d1ebd", "openstack_version": "2015.1.0-7.0", "fuel-agent_sha": "082a47bf014002e515001be05f99040437281a2d", "production": "docker", "python-fuelclient_sha": "1ce8ecd8beb640f2f62f73435f4e18d1469979ac", "astute_sha": "a717657232721a7fafc67ff5e1c696c9dbeb0b95", "fuel-ostf_sha": "1f08e6e71021179b9881a824d9c999957fcc7045", "release": "7.0", "fuelmain_sha": "6b83d6a6a75bf7bca3177fcf63b2eebbf1ad0a85"}