Ask Your Question

Revision history [back]

click to hide/show revision 1
initial version

stack-create sometimes fails

about 50% times, my very simple stack-create (in an allinone Juno rdo installation), fails on floatingip association step with message "Resource CREATE failed: BadRequest: No nw_info cache associated with instance (HTTP 400) ..." Every time this happens, I juste delete and create again, and its ok, but I'd like to understand the issue. It looks like an operation does not always have the time to complete before the association is created.

heat-engine log show

2015-08-26 09:57:53.950 28805 INFO heat.engine.service [req-6af0d1b4-0496-4998-9432-7bcdde640396 None] Creating stack mystack-2
2015-08-26 09:57:53.971 28805 INFO heat.engine.resource [req-6af0d1b4-0496-4998-9432-7bcdde640396 None] Validating Port "instance_port"
2015-08-26 09:57:53.972 28805 INFO heat.engine.resource [req-6af0d1b4-0496-4998-9432-7bcdde640396 None] Validating Port "instance_ha_port"
2015-08-26 09:57:53.973 28805 INFO heat.engine.resource [req-6af0d1b4-0496-4998-9432-7bcdde640396 None] Validating NovaFloatingIp "floating_ip"
2015-08-26 09:57:53.973 28805 INFO heat.engine.resource [req-6af0d1b4-0496-4998-9432-7bcdde640396 None] Validating Server "instance"
2015-08-26 09:57:54.410 28805 INFO heat.engine.resource [req-6af0d1b4-0496-4998-9432-7bcdde640396 None] Validating NovaFloatingIpAssociation "association"
2015-08-26 09:57:54.717 28805 INFO heat.engine.stack [-] Stack CREATE IN_PROGRESS (mystack-2): Stack CREATE started
2015-08-26 09:57:54.718 28805 INFO heat.engine.resource [-] creating Port "instance_port" Stack "mystack-2" [fdd2406c-d362-45ed-9b57-2a66b75ca33e]
2015-08-26 09:57:54.899 28805 INFO heat.engine.resource [-] creating Port "instance_ha_port" Stack "mystack-2" [fdd2406c-d362-45ed-9b57-2a66b75ca33e]
2015-08-26 09:57:55.106 28805 INFO heat.engine.resource [-] creating NovaFloatingIp "floating_ip" Stack "mystack-2" [fdd2406c-d362-45ed-9b57-2a66b75ca33e]
2015-08-26 09:57:56.607 28805 INFO heat.engine.resource [-] creating Server "instance" Stack "mystack-2" [fdd2406c-d362-45ed-9b57-2a66b75ca33e]
2015-08-26 09:59:09.298 28805 INFO heat.engine.resource [-] creating NovaFloatingIpAssociation "association" Stack "mystack-2" [fdd2406c-d362-45ed-9b57-2a66b75ca33e]
2015-08-26 09:59:09.500 28805 INFO heat.engine.resource [-] CREATE: NovaFloatingIpAssociation "association" Stack "mystack-2" [fdd2406c-d362-45ed-9b57-2a66b75ca33e]
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource Traceback (most recent call last):
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/resource.py", line 439, in _action_recorder
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource     yield
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/resource.py", line 509, in _do_action
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource     yield self.action_handler_task(action, args=handler_args)
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/scheduler.py", line 286, in wrapper
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource     step = next(subtask)
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/resource.py", line 480, in action_handler_task
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource     handler_data = handler(*args)
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/resources/nova_floatingip.py", line 124, in handle_create
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource     self.nova().servers.add_floating_ip(server, fl_ip.ip)
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource   File "/usr/lib/python2.7/site-packages/novaclient/v1_1/servers.py", line 640, in add_floating_ip
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource     self._action('addFloatingIp', server, {'address': address})
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource   File "/usr/lib/python2.7/site-packages/novaclient/v1_1/servers.py", line 1240, in _action
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource     return self.api.client.post(url, body=body)
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource   File "/usr/lib/python2.7/site-packages/novaclient/client.py", line 490, in post
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource     return self._cs_request(url, 'POST', **kwargs)
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource   File "/usr/lib/python2.7/site-packages/novaclient/client.py", line 465, in _cs_request
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource     resp, body = self._time_request(url, method, **kwargs)
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource   File "/usr/lib/python2.7/site-packages/novaclient/client.py", line 439, in _time_request
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource     resp, body = self.request(url, method, **kwargs)
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource   File "/usr/lib/python2.7/site-packages/novaclient/client.py", line 433, in request
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource     raise exceptions.from_response(resp, body, url, method)
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource BadRequest: No nw_info cache associated with instance (HTTP 400) (Request-ID: req-4ae88fbc-7d29-4865-83d0-8e611e9a1d51)
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource
2015-08-26 09:59:10.521 28805 INFO heat.engine.stack [-] Stack CREATE FAILED (mystack-2): Resource CREATE failed: BadRequest: No nw_info cache associated with instance (HTTP 400) (Request-ID: req-4ae88fbc-7d29-4865-83d0-8e611e9a1d51)

The template merely contains (for this aspect):

resources:

  instance:
    type: OS::Nova::Server
    properties:
    name: mysrv1
    ...

  floating_ip:
    type: OS::Nova::FloatingIP
    properties:
      pool: "public"
  ...
  association:
    type: OS::Nova::FloatingIPAssociation
    properties:
      floating_ip: { get_resource: floating_ip }
      server_id: { get_resource: instance }

thanks for help.

stack-create sometimes fails

about 50% times, my very simple stack-create (in an allinone Juno rdo installation), fails on floatingip association step with message "Resource CREATE failed: BadRequest: No nw_info cache associated with instance (HTTP 400) ..." Every time this happens, I juste delete and create again, and its ok, but I'd like to understand the issue. It When it fails, it looks like an operation does in instance launching is delayed.

See nova-compute log below, the message "WARNING nova.virt.disk.vfs.guestfs [-] Failed to close augeas aug_close: do_aug_close: you must call 'aug-init' first " comaes about 1mn after the instance is launched.

The nova-compute.log shows the following

2015-08-26 12:02:44.543 13393 AUDIT nova.compute.manager [req-fc773400-3b5d-40d9-beaf-7db35959f279 None] [instance: 2f4e97fe-6126-4ef5-8dbc-72a2d841a9ad] Starting instance...
2015-08-26 12:02:44.614 13393 AUDIT nova.compute.claims [-] [instance: 2f4e97fe-6126-4ef5-8dbc-72a2d841a9ad] Attempting claim: memory 2048 MB, disk 20 GB
2015-08-26 12:02:44.615 13393 AUDIT nova.compute.claims [-] [instance: 2f4e97fe-6126-4ef5-8dbc-72a2d841a9ad] Total memory: 11842 MB, used: 512.00 MB
2015-08-26 12:02:44.615 13393 AUDIT nova.compute.claims [-] [instance: 2f4e97fe-6126-4ef5-8dbc-72a2d841a9ad] memory limit: 17763.00 MB, free: 17251.00 MB
2015-08-26 12:02:44.615 13393 AUDIT nova.compute.claims [-] [instance: 2f4e97fe-6126-4ef5-8dbc-72a2d841a9ad] Total disk: 49 GB, used: 0.00 GB
2015-08-26 12:02:44.615 13393 AUDIT nova.compute.claims [-] [instance: 2f4e97fe-6126-4ef5-8dbc-72a2d841a9ad] disk limit not always have the time specified, defaulting to complete before the association is created. 

unlimited 2015-08-26 12:02:44.625 13393 AUDIT nova.compute.claims [-] [instance: 2f4e97fe-6126-4ef5-8dbc-72a2d841a9ad] Claim successful 2015-08-26 12:02:44.717 13393 INFO nova.scheduler.client.report [-] Compute_service record updated for ('pstack149', 'pstack149') 2015-08-26 12:02:44.815 13393 INFO nova.scheduler.client.report [-] Compute_service record updated for ('pstack149', 'pstack149') 2015-08-26 12:02:45.053 13393 INFO nova.virt.libvirt.driver [-] [instance: 2f4e97fe-6126-4ef5-8dbc-72a2d841a9ad] Creating image 2015-08-26 12:02:53.281 13393 INFO nova.scheduler.client.report [-] Compute_service record updated for ('pstack149', 'pstack149') 2015-08-26 12:02:54.620 13393 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources 2015-08-26 12:02:54.808 13393 AUDIT nova.compute.resource_tracker [-] Total physical ram (MB): 11842, total allocated virtual ram (MB): 2560 2015-08-26 12:02:54.808 13393 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 29 2015-08-26 12:02:54.808 13393 AUDIT nova.compute.resource_tracker [-] Total usable vcpus: 8, total allocated vcpus: 0 2015-08-26 12:02:54.809 13393 AUDIT nova.compute.resource_tracker [-] PCI stats: [] 2015-08-26 12:02:55.364 13393 INFO nova.scheduler.client.report [-] Compute_service record updated for ('pstack149', 'pstack149') 2015-08-26 12:02:55.364 13393 INFO nova.compute.resource_tracker [-] Compute_service record updated for pstack149:pstack149 2015-08-26 12:03:51.207 13393 WARNING nova.virt.disk.vfs.guestfs [-] Failed to close augeas aug_close: do_aug_close: you must call 'aug-init' first to initialize Augeas 2015-08-26 12:03:51.261 13393 INFO nova.virt.libvirt.driver [-] [instance: 2f4e97fe-6126-4ef5-8dbc-72a2d841a9ad] Using config drive 2015-08-26 12:03:51.329 13393 INFO nova.virt.libvirt.driver [-] [instance: 2f4e97fe-6126-4ef5-8dbc-72a2d841a9ad] Creating config drive at /var/lib/nova/instances/2f4e97fe-6126-4ef5-8dbc-72a2d841a9ad/disk.config

heat-engine log show

2015-08-26 09:57:53.950 28805 INFO heat.engine.service [req-6af0d1b4-0496-4998-9432-7bcdde640396 None] Creating stack mystack-2
2015-08-26 09:57:53.971 28805 INFO heat.engine.resource [req-6af0d1b4-0496-4998-9432-7bcdde640396 None] Validating Port "instance_port"
2015-08-26 09:57:53.972 28805 INFO heat.engine.resource [req-6af0d1b4-0496-4998-9432-7bcdde640396 None] Validating Port "instance_ha_port"
2015-08-26 09:57:53.973 28805 INFO heat.engine.resource [req-6af0d1b4-0496-4998-9432-7bcdde640396 None] Validating NovaFloatingIp "floating_ip"
2015-08-26 09:57:53.973 28805 INFO heat.engine.resource [req-6af0d1b4-0496-4998-9432-7bcdde640396 None] Validating Server "instance"
2015-08-26 09:57:54.410 28805 INFO heat.engine.resource [req-6af0d1b4-0496-4998-9432-7bcdde640396 None] Validating NovaFloatingIpAssociation "association"
2015-08-26 09:57:54.717 28805 INFO heat.engine.stack [-] Stack CREATE IN_PROGRESS (mystack-2): Stack CREATE started
2015-08-26 09:57:54.718 28805 INFO heat.engine.resource [-] creating Port "instance_port" Stack "mystack-2" [fdd2406c-d362-45ed-9b57-2a66b75ca33e]
2015-08-26 09:57:54.899 28805 INFO heat.engine.resource [-] creating Port "instance_ha_port" Stack "mystack-2" [fdd2406c-d362-45ed-9b57-2a66b75ca33e]
2015-08-26 09:57:55.106 28805 INFO heat.engine.resource [-] creating NovaFloatingIp "floating_ip" Stack "mystack-2" [fdd2406c-d362-45ed-9b57-2a66b75ca33e]
2015-08-26 09:57:56.607 28805 INFO heat.engine.resource [-] creating Server "instance" Stack "mystack-2" [fdd2406c-d362-45ed-9b57-2a66b75ca33e]
2015-08-26 09:59:09.298 28805 INFO heat.engine.resource [-] creating NovaFloatingIpAssociation "association" Stack "mystack-2" [fdd2406c-d362-45ed-9b57-2a66b75ca33e]
2015-08-26 09:59:09.500 28805 INFO heat.engine.resource [-] CREATE: NovaFloatingIpAssociation "association" Stack "mystack-2" [fdd2406c-d362-45ed-9b57-2a66b75ca33e]
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource Traceback (most recent call last):
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/resource.py", line 439, in _action_recorder
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource     yield
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/resource.py", line 509, in _do_action
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource     yield self.action_handler_task(action, args=handler_args)
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/scheduler.py", line 286, in wrapper
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource     step = next(subtask)
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/resource.py", line 480, in action_handler_task
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource     handler_data = handler(*args)
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/resources/nova_floatingip.py", line 124, in handle_create
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource     self.nova().servers.add_floating_ip(server, fl_ip.ip)
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource   File "/usr/lib/python2.7/site-packages/novaclient/v1_1/servers.py", line 640, in add_floating_ip
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource     self._action('addFloatingIp', server, {'address': address})
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource   File "/usr/lib/python2.7/site-packages/novaclient/v1_1/servers.py", line 1240, in _action
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource     return self.api.client.post(url, body=body)
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource   File "/usr/lib/python2.7/site-packages/novaclient/client.py", line 490, in post
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource     return self._cs_request(url, 'POST', **kwargs)
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource   File "/usr/lib/python2.7/site-packages/novaclient/client.py", line 465, in _cs_request
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource     resp, body = self._time_request(url, method, **kwargs)
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource   File "/usr/lib/python2.7/site-packages/novaclient/client.py", line 439, in _time_request
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource     resp, body = self.request(url, method, **kwargs)
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource   File "/usr/lib/python2.7/site-packages/novaclient/client.py", line 433, in request
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource     raise exceptions.from_response(resp, body, url, method)
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource BadRequest: No nw_info cache associated with instance (HTTP 400) (Request-ID: req-4ae88fbc-7d29-4865-83d0-8e611e9a1d51)
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource
2015-08-26 09:59:10.521 28805 INFO heat.engine.stack [-] Stack CREATE FAILED (mystack-2): Resource CREATE failed: BadRequest: No nw_info cache associated with instance (HTTP 400) (Request-ID: req-4ae88fbc-7d29-4865-83d0-8e611e9a1d51)

The template merely contains (for this aspect):

resources:

  instance:
    type: OS::Nova::Server
    properties:
    name: mysrv1
    ...

  floating_ip:
    type: OS::Nova::FloatingIP
    properties:
      pool: "public"
  ...
  association:
    type: OS::Nova::FloatingIPAssociation
    properties:
      floating_ip: { get_resource: floating_ip }
      server_id: { get_resource: instance }

thanks for help.

stack-create sometimes failsfails - server instance launch causing delay.

about 50% times, my very simple stack-create (in an allinone Juno rdo installation), fails on floatingip association step with message "Resource CREATE failed: BadRequest: No nw_info cache associated with instance (HTTP 400) ..." Every time this happens, I juste delete and create again, and its ok, but I'd like to understand the issue. When it fails, it looks like an operation in instance launching is delayed.

See In nova-compute log below, (see below), the only difference I see hen it goes wrong, is a delay of about 1mn instead of 1sec before the message "WARNING nova.virt.disk.vfs.guestfs [-] Failed to close augeas aug_close: do_aug_close: you must call 'aug-init' first " comaes about 1mn after the instance is launched. ". (and some audit messages in between, at random delay).

The nova-compute.log shows the following of server launch extract :

2015-08-26 12:02:44.543 13393 AUDIT nova.compute.manager [req-fc773400-3b5d-40d9-beaf-7db35959f279 None] [instance: 2f4e97fe-6126-4ef5-8dbc-72a2d841a9ad] Starting instance...
2015-08-26 12:02:44.614 13393 AUDIT nova.compute.claims [-] [instance: 2f4e97fe-6126-4ef5-8dbc-72a2d841a9ad] Attempting claim: memory 2048 MB, disk 20 GB
2015-08-26 12:02:44.615 13393 AUDIT nova.compute.claims [-] [instance: 2f4e97fe-6126-4ef5-8dbc-72a2d841a9ad] Total memory: 11842 MB, used: 512.00 MB
2015-08-26 12:02:44.615 13393 AUDIT nova.compute.claims [-] [instance: 2f4e97fe-6126-4ef5-8dbc-72a2d841a9ad] memory limit: 17763.00 MB, free: 17251.00 MB
2015-08-26 12:02:44.615 13393 AUDIT nova.compute.claims [-] [instance: 2f4e97fe-6126-4ef5-8dbc-72a2d841a9ad] Total disk: 49 GB, used: 0.00 GB
2015-08-26 12:02:44.615 13393 AUDIT nova.compute.claims [-] [instance: 2f4e97fe-6126-4ef5-8dbc-72a2d841a9ad] disk limit not specified, defaulting to unlimited
2015-08-26 12:02:44.625 13393 AUDIT nova.compute.claims [-] [instance: 2f4e97fe-6126-4ef5-8dbc-72a2d841a9ad] Claim successful
2015-08-26 12:02:44.717 13393 INFO nova.scheduler.client.report [-] Compute_service record updated for ('pstack149', 'pstack149')
2015-08-26 12:02:44.815 13393 INFO nova.scheduler.client.report [-] Compute_service record updated for ('pstack149', 'pstack149')
2015-08-26 12:02:45.053 13393 INFO nova.virt.libvirt.driver [-] [instance: 2f4e97fe-6126-4ef5-8dbc-72a2d841a9ad] Creating image
2015-08-26 12:02:53.281 13393 INFO nova.scheduler.client.report [-] Compute_service record updated for ('pstack149', 'pstack149')
2015-08-26 12:02:54.620 13393 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2015-08-26 12:02:54.808 13393 AUDIT nova.compute.resource_tracker [-] Total physical ram (MB): 11842, total allocated virtual ram (MB): 2560
2015-08-26 12:02:54.808 13393 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 29
2015-08-26 12:02:54.808 13393 AUDIT nova.compute.resource_tracker [-] Total usable vcpus: 8, total allocated vcpus: 0
2015-08-26 12:02:54.809 13393 AUDIT nova.compute.resource_tracker [-] PCI stats: []
2015-08-26 12:02:55.364 13393 INFO nova.scheduler.client.report [-] Compute_service record updated for ('pstack149', 'pstack149')
2015-08-26 12:02:55.364 13393 INFO nova.compute.resource_tracker [-] Compute_service record updated for pstack149:pstack149
2015-08-26 12:03:51.207 13393 WARNING nova.virt.disk.vfs.guestfs [-] Failed to close augeas aug_close: do_aug_close: you must call 'aug-init' first to initialize Augeas
2015-08-26 12:03:51.261 13393 INFO nova.virt.libvirt.driver [-] [instance: 2f4e97fe-6126-4ef5-8dbc-72a2d841a9ad] Using config drive
2015-08-26 12:03:51.329 13393 INFO nova.virt.libvirt.driver [-] [instance: 2f4e97fe-6126-4ef5-8dbc-72a2d841a9ad] Creating config drive at /var/lib/nova/instances/2f4e97fe-6126-4ef5-8dbc-72a2d841a9ad/disk.config

heat-engine log show

2015-08-26 09:57:53.950 28805 INFO heat.engine.service [req-6af0d1b4-0496-4998-9432-7bcdde640396 None] Creating stack mystack-2
2015-08-26 09:57:53.971 28805 INFO heat.engine.resource [req-6af0d1b4-0496-4998-9432-7bcdde640396 None] Validating Port "instance_port"
2015-08-26 09:57:53.972 28805 INFO heat.engine.resource [req-6af0d1b4-0496-4998-9432-7bcdde640396 None] Validating Port "instance_ha_port"
2015-08-26 09:57:53.973 28805 INFO heat.engine.resource [req-6af0d1b4-0496-4998-9432-7bcdde640396 None] Validating NovaFloatingIp "floating_ip"
2015-08-26 09:57:53.973 28805 INFO heat.engine.resource [req-6af0d1b4-0496-4998-9432-7bcdde640396 None] Validating Server "instance"
2015-08-26 09:57:54.410 28805 INFO heat.engine.resource [req-6af0d1b4-0496-4998-9432-7bcdde640396 None] Validating NovaFloatingIpAssociation "association"
2015-08-26 09:57:54.717 28805 INFO heat.engine.stack [-] Stack CREATE IN_PROGRESS (mystack-2): Stack CREATE started
2015-08-26 09:57:54.718 28805 INFO heat.engine.resource [-] creating Port "instance_port" Stack "mystack-2" [fdd2406c-d362-45ed-9b57-2a66b75ca33e]
2015-08-26 09:57:54.899 28805 INFO heat.engine.resource [-] creating Port "instance_ha_port" Stack "mystack-2" [fdd2406c-d362-45ed-9b57-2a66b75ca33e]
2015-08-26 09:57:55.106 28805 INFO heat.engine.resource [-] creating NovaFloatingIp "floating_ip" Stack "mystack-2" [fdd2406c-d362-45ed-9b57-2a66b75ca33e]
2015-08-26 09:57:56.607 28805 INFO heat.engine.resource [-] creating Server "instance" Stack "mystack-2" [fdd2406c-d362-45ed-9b57-2a66b75ca33e]
2015-08-26 09:59:09.298 28805 INFO heat.engine.resource [-] creating NovaFloatingIpAssociation "association" Stack "mystack-2" [fdd2406c-d362-45ed-9b57-2a66b75ca33e]
2015-08-26 09:59:09.500 28805 INFO heat.engine.resource [-] CREATE: NovaFloatingIpAssociation "association" Stack "mystack-2" [fdd2406c-d362-45ed-9b57-2a66b75ca33e]
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource Traceback (most recent call last):
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/resource.py", line 439, in _action_recorder
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource     yield
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/resource.py", line 509, in _do_action
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource     yield self.action_handler_task(action, args=handler_args)
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/scheduler.py", line 286, in wrapper
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource     step = next(subtask)
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/resource.py", line 480, in action_handler_task
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource     handler_data = handler(*args)
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource   File "/usr/lib/python2.7/site-packages/heat/engine/resources/nova_floatingip.py", line 124, in handle_create
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource     self.nova().servers.add_floating_ip(server, fl_ip.ip)
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource   File "/usr/lib/python2.7/site-packages/novaclient/v1_1/servers.py", line 640, in add_floating_ip
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource     self._action('addFloatingIp', server, {'address': address})
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource   File "/usr/lib/python2.7/site-packages/novaclient/v1_1/servers.py", line 1240, in _action
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource     return self.api.client.post(url, body=body)
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource   File "/usr/lib/python2.7/site-packages/novaclient/client.py", line 490, in post
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource     return self._cs_request(url, 'POST', **kwargs)
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource   File "/usr/lib/python2.7/site-packages/novaclient/client.py", line 465, in _cs_request
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource     resp, body = self._time_request(url, method, **kwargs)
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource   File "/usr/lib/python2.7/site-packages/novaclient/client.py", line 439, in _time_request
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource     resp, body = self.request(url, method, **kwargs)
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource   File "/usr/lib/python2.7/site-packages/novaclient/client.py", line 433, in request
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource     raise exceptions.from_response(resp, body, url, method)
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource BadRequest: No nw_info cache associated with instance (HTTP 400) (Request-ID: req-4ae88fbc-7d29-4865-83d0-8e611e9a1d51)
2015-08-26 09:59:09.500 28805 TRACE heat.engine.resource
2015-08-26 09:59:10.521 28805 INFO heat.engine.stack [-] Stack CREATE FAILED (mystack-2): Resource CREATE failed: BadRequest: No nw_info cache associated with instance (HTTP 400) (Request-ID: req-4ae88fbc-7d29-4865-83d0-8e611e9a1d51)

The template merely contains (for this aspect):

resources:

  instance:
    type: OS::Nova::Server
    properties:
    name: mysrv1
    ...

  floating_ip:
    type: OS::Nova::FloatingIP
    properties:
      pool: "public"
  ...
  association:
    type: OS::Nova::FloatingIPAssociation
    properties:
      floating_ip: { get_resource: floating_ip }
      server_id: { get_resource: instance }

thanks for help.