OpenStack Heat

Create stack failed because of "Invalid Volume: Status"

Bug #1390727 reported by Samuel Chen
8
This bug affects 1 person
Affects Status Importance Assigned to Milestone
OpenStack Heat
Invalid
Undecided
Unassigned

Bug Description

Hi,
   My system is Juno on CentOS7.
    I created a 6 VMs stack. It seemed that all VMS were active and each volume had been attached to VMs.
But the stack is failed with below error:

|
| stack_status_reason | Resource CREATE failed: BadRequest: Invalid volume: |
| | status must be 'available' (HTTP 400) (Request-ID: req- |
| | 9b944545-f704-46fa-beb7-d50cab6a03c2)

 nova list output:
| c492eec8-5bcb-4f94-b566-10e10de6ec1a | abc301-0-0-1 | ACTIVE | - | Running | abc301-network:intnet1:net=169.30.1.3; OAM121=192.168.121.48 |
| cf46e025-2052-4a89-8d86-8ac558076c93 | abc301-0-0-10 | ACTIVE | - | Running | abc301-network:intnet1:net=169.30.1.5; SIG123=192.168.123.49 |
| b35dcdab-1942-4760-a76b-c8ac7bddfaa9 | abc301-0-0-11 | ACTIVE | - | Running | abc301-network:intnet1:net=169.30.1.6 |
| af78a5ce-9240-4501-ac1b-08110e31a450 | abc301-0-0-2 | ACTIVE | - | Running | abc301-network:intnet1:net=169.30.1.4; SIG123=192.168.123.47 |
| 0007cad0-1207-456c-9e5d-2c03a4c75213 | abc301-0-0-3 | ACTIVE | - | Running | abc301-network:intnet1:net=169.30.1.8 |
| dcee5e3f-c1ea-4c6d-af3f-6b7022f3fc60 | abc301-0-0-9 | ACTIVE | - | Running | abc301-network:intnet1:net=169.30.1.7; OAM121=192.168.121.49 |

cinder list output:
+--------------------------------------+--------+---------------------+------+-------------+----------+--------------------------------------+
| ID | Status | Display Name | Size | Volume Type | Bootable | Attached to |
+--------------------------------------+--------+---------------------+------+-------------+----------+--------------------------------------+
| 1d509fa9-cdfd-43e4-bc8c-849b4d4cb200 | in-use | abc301-0-0-11:vdb | 20 | None | false | b35dcdab-1942-4760-a76b-c8ac7bddfaa9 |
| 5d730fa7-e4c2-48e9-9025-77b93c821a86 | in-use | abc301-0-0-9:vdb | 40 | None | false | dcee5e3f-c1ea-4c6d-af3f-6b7022f3fc60 |
| 98f44484-8a85-4a33-b808-120ea428afef | in-use | abc301-0-0-3:vdb | 20 | None | false | 0007cad0-1207-456c-9e5d-2c03a4c75213 |
| cef452fd-5e8a-400a-b12f-b7142222236a | in-use | abc301-0-0-1:vdb | 40 | None | false | c492eec8-5bcb-4f94-b566-10e10de6ec1a |
| d7b4f675-a0ff-4d7d-a990-b7671b1c050e | in-use | abc301-0-0-10:vdb | 1 | None | false | cf46e025-2052-4a89-8d86-8ac558076c93 |
| f1bdaa21-7b0e-4892-8bab-39578e8003bd | in-use | abc301-0-0-2:vdb | 1 | None | false | af78a5ce-9240-4501-ac1b-08110e31a450 |
+--------------------------------------+--------+---------------------+------+-------------+----------+--------------------------------------+

From the engine.log, It seems that heat tried to repeat attaching volume. The volume has been attached.

2014-11-08 20:03:36.194 12386 DEBUG heat.engine.scheduler [-] Task VolumeAttachTask(1d509fa9-cdfd-43e4-bc8c-849b4d4cb200 -> b35dcdab-1942-4760-a76b-c8ac7bddfaa9 [None]) starting start /usr/lib/python2.7/site-packages/heat/engine/scheduler.py:182
2014-11-08 20:03:36.194 12386 DEBUG heat.engine.scheduler [-] Task VolumeAttachTask(1d509fa9-cdfd-43e4-bc8c-849b4d4cb200 -> b35dcdab-1942-4760-a76b-c8ac7bddfaa9 [None]) running step /usr/lib/python2.7/site-packages/heat/engine/scheduler.py:210
2014-11-08 20:03:36.195 12386 DEBUG heat.engine.resources.volume [-] Attaching Volume 1d509fa9-cdfd-43e4-bc8c-849b4d4cb200 to Instance b35dcdab-1942-4760-a76b-c8ac7bddfaa9 as None __call__ /usr/lib/python2.7/site-packages/heat/engine/resources/volume.py:267
2014-11-08 20:03:36.196 12386 INFO urllib3.connectionpool [-] Starting new HTTP connection (1): jn-controller
2014-11-08 20:03:36.503 12386 DEBUG urllib3.connectionpool [-] "POST /v2/44294864bdb6486f859a5f6273b0569d/servers/b35dcdab-1942-4760-a76b-c8ac7bddfaa9/os-volume_attachments HTTP/1.1" 400 86 _make_request /usr/lib/python2.7/site-packages/urllib3/connectionpool.py:357
2014-11-08 20:03:36.504 12386 INFO heat.engine.resource [-] CREATE: CinderVolumeAttachment "node:0-0-11:vdb:attach" Stack "abc301" [078e1fb1-cab6-44bb-8436-bb37d82b22cc]
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource Traceback (most recent call last):
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource File "/usr/lib/python2.7/site-packages/heat/engine/resource.py", line 435, in _action_recorder
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource yield
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource File "/usr/lib/python2.7/site-packages/heat/engine/resource.py", line 505, in _do_action
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource yield self.action_handler_task(action, args=handler_args)
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource File "/usr/lib/python2.7/site-packages/heat/engine/scheduler.py", line 286, in wrapper
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource step = next(subtask)
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource File "/usr/lib/python2.7/site-packages/heat/engine/resource.py", line 476, in action_handler_task
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource handler_data = handler(*args)
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource File "/usr/lib/python2.7/site-packages/heat/engine/resources/volume.py", line 431, in handle_create
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource attach_runner.start()
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource File "/usr/lib/python2.7/site-packages/heat/engine/scheduler.py", line 190, in start
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource self.step()
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource File "/usr/lib/python2.7/site-packages/heat/engine/scheduler.py", line 213, in step
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource next(self._runner)
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource File "/usr/lib/python2.7/site-packages/heat/engine/resources/volume.py", line 272, in __call__
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource device=self.device)
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource File "/usr/lib/python2.7/site-packages/novaclient/v1_1/volumes.py", line 119, in create_server_volume
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource body, "volumeAttachment")
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource File "/usr/lib/python2.7/site-packages/novaclient/base.py", line 100, in _create
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource _resp, body = self.api.client.post(url, body=body)
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource File "/usr/lib/python2.7/site-packages/novaclient/client.py", line 490, in post
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource return self._cs_request(url, 'POST', **kwargs)
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource File "/usr/lib/python2.7/site-packages/novaclient/client.py", line 465, in _cs_request
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource resp, body = self._time_request(url, method, **kwargs)
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource File "/usr/lib/python2.7/site-packages/novaclient/client.py", line 439, in _time_request
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource resp, body = self.request(url, method, **kwargs)
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource File "/usr/lib/python2.7/site-packages/novaclient/client.py", line 433, in request
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource raise exceptions.from_response(resp, body, url, method)
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource BadRequest: Invalid volume: status must be 'available' (HTTP 400) (Request-ID: req-9b944545-f704-46fa-beb7-d50cab6a03c2)
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource

All heat engine debug and verbose log attached.

Revision history for this message
Samuel Chen (samuel.chen) wrote :
Revision history for this message
huangtianhua (huangtianhua) wrote :

It seems that the volume is not in available status, and not allow to attach to an instance.
Can you reproduce?

Revision history for this message
Samuel Chen (samuel.chen) wrote :
Download full text (4.3 KiB)

Yes this issue can be reproduced in my count env.

From attached engine.log (enable debug and verbose):
Before error, volume "node:0-0-11:vdb:attach" had been attached to VM.
2014-11-08 20:03:08.743 12386 INFO heat.engine.resource [req-8fa4c4e2-1906-41fa-bfb3-1aa1be62800d None] Validating CinderVolumeAttachment "node:0-0-11:vdb:attach"
2014-11-08 20:03:08.744 12386 INFO heat.engine.resource [req-8fa4c4e2-1906-41fa-bfb3-1aa1be62800d None] Validating Server "node:0-0-1:server"

Attache again here?
2014-11-08 20:03:36.504 12386 INFO heat.engine.resource [-] CREATE: CinderVolumeAttachment "node:0-0-11:vdb:attach" Stack "abc301" [078e1fb1-cab6-44bb-8436-bb37d82b22cc]
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource Traceback (most recent call last):
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource File "/usr/lib/python2.7/site-packages/heat/engine/resource.py", line 435, in _action_recorder
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource yield
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource File "/usr/lib/python2.7/site-packages/heat/engine/resource.py", line 505, in _do_action
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource yield self.action_handler_task(action, args=handler_args)
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource File "/usr/lib/python2.7/site-packages/heat/engine/scheduler.py", line 286, in wrapper
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource step = next(subtask)
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource File "/usr/lib/python2.7/site-packages/heat/engine/resource.py", line 476, in action_handler_task
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource handler_data = handler(*args)
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource File "/usr/lib/python2.7/site-packages/heat/engine/resources/volume.py", line 431, in handle_create
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource attach_runner.start()
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource File "/usr/lib/python2.7/site-packages/heat/engine/scheduler.py", line 190, in start
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource self.step()
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource File "/usr/lib/python2.7/site-packages/heat/engine/scheduler.py", line 213, in step
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource next(self._runner)
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource File "/usr/lib/python2.7/site-packages/heat/engine/resources/volume.py", line 272, in __call__
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource device=self.device)
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource File "/usr/lib/python2.7/site-packages/novaclient/v1_1/volumes.py", line 119, in create_server_volume
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource body, "volumeAttachment")
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource File "/usr/lib/python2.7/site-packages/novaclient/base.py", line 100, in _create
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resource _resp, body = self.api.client.post(url, body=body)
2014-11-08 20:03:36.504 12386 TRACE heat.engine.resour...

Read more...

Revision history for this message
Samuel Chen (samuel.chen) wrote :
Download full text (6.6 KiB)

I also used below template file to create the stack, same issue. vm was active, cinder volume was in-use, but stack failed

[<email address hidden> /root/161 ]# nova list
+--------------------------------------+--------------+--------+------------+-------------+-----------------------------------------+
| ID | Name | Status | Task State | Power State | Networks |
 +--------------------------------------+--------------+--------+------------+-------------+-----------------------------------------+
| 1faf221e-dc14-4acf-9abb-c743e62a9e68 | vm001 | ACTIVE | - | Running | OAM120=192.168.120.155 |
 +--------------------------------------+--------------+--------+------------+-------------+-----------------------------------------+
[<email address hidden> /root/161 ]# cinder list
+--------------------------------------+--------+--------------+------+-------------+----------+--------------------------------------+
| ID | Status | Display Name | Size | Volume Type | Bootable | Attached to |
 +--------------------------------------+--------+--------------+------+-------------+----------+--------------------------------------+
| 55c9e7be-9fba-41c9-857f-3657c2bcf8d8 | in-use | node:vdb | 40 | None | false | 1faf221e-dc14-4acf-9abb-c743e62a9e68 |
 +--------------------------------------+--------+--------------+------+-------------+----------+--------------------------------------+
[<email address hidden> /root/xmchen/161 ]#

[<email address hidden> /root/xmchen/161 ]# heat stack-show my
+----------------------+----------------------------------------------------------------------------------------------------------------+
| Property | Value |
 +----------------------+----------------------------------------------------------------------------------------------------------------+
| capabilities | [] |
| creation_time | 2014-11-18T14:00:35Z |
| description | No description |
| disable_rollback | True |
| id | 18282879-ffdc-43f3-94cf-ff2d9561f046 |
| links | http://:8004/v1/44294864bdb6486f859a5f6273b0569d/stacks/my/18282879-ffdc-43f3-94cf-ff2d9561f046 |
| notification_topics | [] |
| outputs | [] |
| param...

Read more...

Revision history for this message
Pavlo Shchelokovskyy (pshchelo) wrote :

IMO the problem with your template is that you are attaching the volume twice - first in the server's block_device_mapping (that by dependency graph will be first), than via VolumeAttachment resource. You should rather use one method only.

Revision history for this message
Samuel Chen (samuel.chen) wrote :

But it does work on Icehouse. Juno enhanced the logic to check the double attaching?

Revision history for this message
Qiming Teng (tengqim) wrote :

Seems more like a template mistake than a heat bug.

Changed in heat:
status: New → Invalid
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.
Subscribing...

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.