InvalidBDMFormat when running exercise/boot_from_volume.sh

[SteveBonds]

1. Exact version of Nova/OpenStack you are running:

$ git log -1
commit b6249dc2ad630ecb9a231d0ce65d0f14f2116598
Merge: 5090142 91b7fa1
Author: Jenkins <email address hidden>
Date: Wed Sep 23 10:28:14 2015 +0000

    Merge "Add manila to devstack plugin registry"

2. Relevant log files:

2015-09-24 08:58:14.736 DEBUG nova.api.openstack.wsgi [req-88fcff38-652c-46bc-83a5-b8bdde7c22ac demo demo] Action: 'create', calling method: <bound method S
erversController.create of <nova.api.openstack.compute.servers.ServersController object at 0x774b510>>, body: {"server": {"name": "ex-bfv-inst", "imageRef":
 "a2b158b9-a7e0-4c51-9bf3-98196d6cd9e9", "block_device_mapping": [{"device_name": "vda"}], "key_name": "test_key", "flavorRef": "1", "max_count": 1, "min_co
unt": 1, "security_groups": [{"name": "boot_secgroup"}]}} from (pid=18220) _process_stack /opt/stack/nova/nova/api/openstack/wsgi.py:789
2015-09-24 08:58:14.737 DEBUG nova.api.openstack.compute.servers [req-88fcff38-652c-46bc-83a5-b8bdde7c22ac demo demo] Running _create_extension_point for <E
xtension: name=SchedulerHints, alias=os-scheduler-hints, version=1> from (pid=18220) _create_extension_point /opt/stack/nova/nova/api/openstack/compute/serv
ers.py:700
2015-09-24 08:58:14.738 DEBUG nova.api.openstack.compute.servers [req-88fcff38-652c-46bc-83a5-b8bdde7c22ac demo demo] Running _create_extension_point for <E
xtension: name=Keypairs, alias=os-keypairs, version=1> from (pid=18220) _create_extension_point /opt/stack/nova/nova/api/openstack/compute/servers.py:700
2015-09-24 08:58:14.738 DEBUG nova.api.openstack.compute.servers [req-88fcff38-652c-46bc-83a5-b8bdde7c22ac demo demo] Running _create_extension_point for <E
xtension: name=BlockDeviceMapping, alias=os-block-device-mapping, version=1> from (pid=18220) _create_extension_point /opt/stack/nova/nova/api/openstack/com
pute/servers.py:700
2015-09-24 08:58:14.738 DEBUG nova.api.openstack.compute.servers [req-88fcff38-652c-46bc-83a5-b8bdde7c22ac demo demo] Running _create_extension_point for <Extension: name=AccessIPs, alias=os-access-ips, version=1> from (pid=18220) _create_extension_point /opt/stack/nova/nova/api/openstack/compute/servers.py:700
2015-09-24 08:58:14.738 DEBUG nova.api.openstack.compute.servers [req-88fcff38-652c-46bc-83a5-b8bdde7c22ac demo demo] Running _create_extension_point for <Extension: name=BlockDeviceMappingV1, alias=os-block-device-mapping-v1, version=1> from (pid=18220) _create_extension_point /opt/stack/nova/nova/api/openstack/compute/servers.py:700
2015-09-24 08:58:14.738 DEBUG nova.api.openstack.compute.servers [req-88fcff38-652c-46bc-83a5-b8bdde7c22ac demo demo] Running _create_extension_point for <Extension: name=DiskConfig, alias=os-disk-config, version=1> from (pid=18220) _create_extension_point /opt/stack/nova/nova/api/openstack/compute/servers.py:700
2015-09-24 08:58:14.739 DEBUG nova.api.openstack.compute.servers [req-88fcff38-652c-46bc-83a5-b8bdde7c22ac demo demo] Running _create_extension_point for <Extension: name=UserData, alias=os-user-data, version=1> from (pid=18220) _create_extension_point /opt/stack/nova/nova/api/openstack/compute/servers.py:700
2015-09-24 08:58:14.739 DEBUG nova.api.openstack.compute.servers [req-88fcff38-652c-46bc-83a5-b8bdde7c22ac demo demo] Running _create_extension_point for <Extension: name=AvailabilityZone, alias=os-availability-zone, version=1> from (pid=18220) _create_extension_point /opt/stack/nova/nova/api/openstack/compute/servers.py:700
2015-09-24 08:58:14.739 DEBUG nova.api.openstack.compute.servers [req-88fcff38-652c-46bc-83a5-b8bdde7c22ac demo demo] Running _create_extension_point for <Extension: name=MultipleCreate, alias=os-multiple-create, version=1> from (pid=18220) _create_extension_point /opt/stack/nova/nova/api/openstack/compute/servers.py:700
2015-09-24 08:58:14.739 DEBUG nova.api.openstack.compute.servers [req-88fcff38-652c-46bc-83a5-b8bdde7c22ac demo demo] Running _create_extension_point for <Extension: name=Personality, alias=os-personality, version=1> from (pid=18220) _create_extension_point /opt/stack/nova/nova/api/openstack/compute/servers.py:700
2015-09-24 08:58:14.739 DEBUG nova.api.openstack.compute.servers [req-88fcff38-652c-46bc-83a5-b8bdde7c22ac demo demo] Running _create_extension_point for <Extension: name=SecurityGroups, alias=os-security-groups, version=1> from (pid=18220) _create_extension_point /opt/stack/nova/nova/api/openstack/compute/servers.py:700
2015-09-24 08:58:14.740 DEBUG nova.api.openstack.compute.servers [req-88fcff38-652c-46bc-83a5-b8bdde7c22ac demo demo] Running _create_extension_point for <Extension: name=ConfigDrive, alias=os-config-drive, version=1> from (pid=18220) _create_extension_point /opt/stack/nova/nova/api/openstack/compute/servers.py:700
2015-09-24 08:58:14.906 ERROR nova.api.openstack.extensions [req-88fcff38-652c-46bc-83a5-b8bdde7c22ac demo demo] Unexpected exception in API method
2015-09-24 08:58:14.906 TRACE nova.api.openstack.extensions Traceback (most recent call last):
2015-09-24 08:58:14.906 TRACE nova.api.openstack.extensions File "/opt/stack/nova/nova/api/openstack/extensions.py", line 478, in wrapped
2015-09-24 08:58:14.906 TRACE nova.api.openstack.extensions return f(*args, **kwargs)
2015-09-24 08:58:14.906 TRACE nova.api.openstack.extensions File "/opt/stack/nova/nova/api/validation/__init__.py", line 73, in wrapper
2015-09-24 08:58:14.906 TRACE nova.api.openstack.extensions return func(*args, **kwargs)
2015-09-24 08:58:14.906 TRACE nova.api.openstack.extensions File "/opt/stack/nova/nova/api/validation/__init__.py", line 73, in wrapper
2015-09-24 08:58:14.906 TRACE nova.api.openstack.extensions return func(*args, **kwargs)
2015-09-24 08:58:14.906 TRACE nova.api.openstack.extensions File "/opt/stack/nova/nova/api/openstack/compute/servers.py", line 611, in create
2015-09-24 08:58:14.906 TRACE nova.api.openstack.extensions **create_kwargs)
2015-09-24 08:58:14.906 TRACE nova.api.openstack.extensions File "/opt/stack/nova/nova/hooks.py", line 149, in inner
2015-09-24 08:58:14.906 TRACE nova.api.openstack.extensions rv = f(*args, **kwargs)
2015-09-24 08:58:14.906 TRACE nova.api.openstack.extensions File "/opt/stack/nova/nova/compute/api.py", line 1581, in create
2015-09-24 08:58:14.906 TRACE nova.api.openstack.extensions check_server_group_quota=check_server_group_quota)
2015-09-24 08:58:14.906 TRACE nova.api.openstack.extensions File "/opt/stack/nova/nova/compute/api.py", line 1197, in _create_instance
2015-09-24 08:58:14.906 TRACE nova.api.openstack.extensions block_device_mapping, legacy_bdm)
2015-09-24 08:58:14.906 TRACE nova.api.openstack.extensions File "/opt/stack/nova/nova/compute/api.py", line 830, in _check_and_transform_bdm
2015-09-24 08:58:14.906 TRACE nova.api.openstack.extensions no_root=root_in_image_bdms)
2015-09-24 08:58:14.906 TRACE nova.api.openstack.extensions File "/opt/stack/nova/nova/block_device.py", line 334, in from_legacy_mapping
2015-09-24 08:58:14.906 TRACE nova.api.openstack.extensions for legacy_bdm in legacy_block_device_mapping]
2015-09-24 08:58:14.906 TRACE nova.api.openstack.extensions File "/opt/stack/nova/nova/block_device.py", line 172, in from_legacy
2015-09-24 08:58:14.906 TRACE nova.api.openstack.extensions details=_("Unrecognized legacy format."))
2015-09-24 08:58:14.906 TRACE nova.api.openstack.extensions InvalidBDMFormat: Block Device Mapping is Invalid: Unrecognized legacy format.
2015-09-24 08:58:14.906 TRACE nova.api.openstack.extensions
2015-09-24 08:58:14.911 INFO nova.api.openstack.wsgi [req-88fcff38-652c-46bc-83a5-b8bdde7c22ac demo demo] HTTP exception thrown: Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.
<class 'nova.exception.InvalidBDMFormat'>
2015-09-24 08:58:14.911 INFO nova.api.openstack.wsgi [req-88fcff38-652c-46bc-83a5-b8bdde7c22ac demo demo] HTTP exception thrown: Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.
<class 'nova.exception.InvalidBDMFormat'>
2015-09-24 08:58:14.911 DEBUG nova.api.openstack.wsgi [req-88fcff38-652c-46bc-83a5-b8bdde7c22ac demo demo] Returning 500 to user: Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.
<class 'nova.exception.InvalidBDMFormat'> from (pid=18220) __call__ /opt/stack/nova/nova/api/openstack/wsgi.py:1175
2015-09-24 08:58:14.912 INFO nova.osapi_compute.wsgi.server [req-88fcff38-652c-46bc-83a5-b8bdde7c22ac demo demo] 172.29.42.70 "POST /v2.1/cb2415a04d4a4027b29e6b636febcdf2/os-volumes_boot HTTP/1.1" status: 500 len: 508 time: 0.1802669

3. Reproduce steps:

I'm working through the early stages of learning OpenStack via this framework: http://docs.openstack.org/developer/devstack/guides/single-machine.html

* I installed CentOS7 minimal
* I patched it via "yum update"
* It has a static IP
* I've set up a small /29 for floating IPs on the same subnet, no DNS/DHCP for them
* I've created the "stack" user and granted sudo
* using the "stack" user I installed devstack via "git clone https://git.openstack.org/openstack-dev/devstack", followed by a local.conf change, and "./stack.sh"

Expected result:
* exercises would complete with success

Actual result:
* fail with this as the last 100 lines of output of the boot_from_volume.sh script:

+ timeout 30 sh -c 'while ! cinder list | grep ex-vol-bfv | grep available; do sleep 1; done'
| 8832e391-3ac1-4569-8ded-6328d7921f3b | available | ex-vol-bfv | 1 | lvmdriver-1 | true | False | |
++ date +%s
+ end_time=1443099493
+ echo 'Completed cinder create in 4 seconds'
Completed cinder create in 4 seconds
++ cinder list
++ grep ex-vol-bfv
++ get_field 1
++ local data field
++ read data
++ '[' 1 -lt 0 ']'
++ field='$2'
++ echo '| 8832e391-3ac1-4569-8ded-6328d7921f3b | available | ex-vol-bfv | 1 | lvmdriver-1 | true | False | |'
++ awk '-F[ \t]*\\|[ \t]*' '{print $2}'
++ read data
+ VOL_ID=8832e391-3ac1-4569-8ded-6328d7921f3b
+ die_if_not_set 162 VOL_ID 'Failure retrieving volume ID for ex-vol-bfv'
+ local exitcode=0
++ set +o
++ grep xtrace
+ local 'xtrace=set -o xtrace'
+ set +o xtrace
++ nova boot --flavor 1 --image a2b158b9-a7e0-4c51-9bf3-98196d6cd9e9 --block-device-mapping vda=8832e391-3ac1-4569-8ded-6328d7921f3b --security-groups=boot_secgroup --key-name test_key ex-bfv-inst
++ grep ' id '
++ get_field 2
++ local data field
++ read data
ERROR (ClientException): Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.
<class 'nova.exception.InvalidBDMFormat'> (HTTP 500) (Request-ID: req-88fcff38-652c-46bc-83a5-b8bdde7c22ac)
+ VM_UUID=
+ die_if_not_set 171 VM_UUID 'Failure launching ex-bfv-inst'
+ local exitcode=0
++ set +o
++ grep xtrace
+ local 'xtrace=set -o xtrace'
+ set +o xtrace
[Call Trace]
./boot_from_volume.sh:171:die_if_not_set
/home/stack/devstack/functions-common:177:die
[ERROR] /home/stack/devstack/functions-common:171 Failure launching ex-bfv-inst

4. Bonus points for reproducing shell script / test:

Hey, this was already included!

Run exercises/boot_from_volume.sh

[Matt Riedemann (mriedem)]

Your git hash is from devstack, not nova, but OK.

[jichenjc (jichenjc)]

seems "block_device_mapping": [{"device_name": "vda"}], is not valid to nova

look at devstack code of boot_from_volume.sh
170 VM_UUID=$(nova boot --flavor $INSTANCE_TYPE --image $IMAGE --block-device-mapping vda=$VOL_ID --security-groups=$SECGROUP --key-name $KEY_N AME $VM_NAME | grep ' id ' | get_field 2)

are the $VOL_ID correctly set?