Disk Attach Error on Deploying Single-VM Bosh Director on vCloud Director


Phong Tran
 

We're currently trying to deploying Single-VM Bosh Director on vCloud Director with bosh-init for one of our test environments and we ran into the error on attaching disk to the VM.

vCloud Director Version: 8.0.2
bosh
bosh-v216-4.tgz
bosh-vcloud-cpi
bosh-vcloud-cpi-v24.tgz
stemcell:
bosh-vcloud-esxi-ubuntu-trusty-go_agent-v3363-15.tgz

boshadmin(a)bosh-init-ubuntu:~/bosh-init$ bosh-init deploy bosh.yml
Deployment manifest: '/home/boshadmin/bosh-init/bosh.yml'
Deployment state: '/home/boshadmin/bosh-init/bosh-state.json'

.... intentionally removed package compiling messages to keep it short ...

Started deploying
Creating VM for instance 'bosh/0' from stemcell 'urn:vcloud:catalogitem:75d662d5-4de9-4b20-8fc2-7754f261314e'... Finished (00:02:59)
Waiting for the agent on VM 'urn:vcloud:vm:a2e227c7-3484-4bdc-afb3-b022dc44198d' to be ready... Finished (00:00:38)
Creating disk... Finished (00:00:22)
Attaching disk 'urn:vcloud:disk:a5da07db-a772-46cd-b65f-6e38cbb7dfcb' to VM 'urn:vcloud:vm:a2e227c7-3484-4bdc-afb3-b022dc44198d'... Failed (00:01:42)
Failed deploying (00:05:42)

Stopping registry... Finished (00:00:00)
Cleaning up rendered CPI jobs... Finished (00:00:00)

Command 'deploy' failed:
Deploying:
Creating instance 'bosh/0':
Updating instance disks:
Updating disks:
Deploying disk:
Attaching disk in the cloud:
CPI 'attach_disk' method responded with error: CmdError{"type":"Unknown","message":"re raising exception Task urn:vcloud:task:f28ba0a0-35a8-48f6-9e7a-e14018af9324 Attached Disk to Virtual Machine 1bcc2f50-c70c-40db-7ffa-eab1d721c876(a2e227c7-3484-4bdc-afb3-b022dc44198d) completed unsuccessfully, Details: [ fba153f1-3b4e-42f7-83e9-82990457c75b-4971 ] The requested operation cannot be performed because th... in attach_disk","ok_to_retry":false}

From the logs in vCloud Director portal, we can see that the disk was successfully attached to the VM on the first try, but it retried to attach the disk 9 more times resulting in the error above as the disk is already attached.

It turned out that the attach disk operation consists of multiple steps. The first step is to sending a request to vCD to attach a disk to the VM and next steps are to update and delete catalog media (ISO) on the VM. All of these steps are wrapped in a retry logic so if one of them fails, all steps are retried for a fixed number of times. With BOSH_INIT_LOG_LEVEL=DEBUG, we can see the real problem is in one of steps used for deleting the catalog item/media failed with 500 server error:

D, [2017-04-20T21:03:48.986129 #6143] DEBUG -- : REST REQ DELETE https://10.145.114.95/api/catalogItem/cf9fca53-df90-4eff-9773-f8b14c5a86d1 {:Accept=>"application/*+xml;version=5.5", :content_type=>"*/*", "X-VMWARE-VCLOUD-CLIENT-REQUEST-ID"=>"d992ba15-cec3-4953-9af3-4132d6a111fd", :x_vcloud_authorization=>"39a0728f4c5143f1b5c94fef578c2bd2"} {"vcloud-token"=>"39a0728f4c5143f1b5c94fef578c2bd2", "Path"=>"%2F"}
D, [2017-04-20T21:03:49.015256 #6143] DEBUG -- : REST RES 500 {:date=>"Thu, 20 Apr 2017 20:03:49 GMT", :x_vmware_vcloud_request_id=>"d992ba15-cec3-4953-9af3-4132d6a111fd-e3c9", :x_vcloud_authorization=>"39a0728f4c5143f1b5c94fef578c2bd2", :set_cookie=>["vcloud-token=39a0728f4c5143f1b5c94fef578c2bd2; Secure; Path=/"], :content_type=>"application/vnd.vmware.vcloud.error+xml;version=5.5", :x_vmware_vcloud_request_execution_time=>"8", :content_length=>"435"} <?xml version="1.0" encoding="UTF-8"?>
<Error xmlns="http://www.vmware.com/vcloud/v1.5" majorErrorCode="500" message="[ d992ba15-cec3-4953-9af3-4132d6a111fd-e3c9 ] Unable to perform this action. Contact your cloud administrator." minorErrorCode="INTERNAL_SERVER_ERROR" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="http://www.vmware.com/vcloud/v1.5 http://10.145.114.95/api/v1.5/schema/master.xsd"></Error>
W, [2017-04-20T21:03:51.469053 #6143] WARN -- : Caught an exception during attach_disk Exception 500 Internal Server Error, Type RestClient::InternalServerError Message 500 Internal Server Error
W, [2017-04-20T21:03:51.469143 #6143] WARN -- : Exception trace /home/boshadmin/.bosh_init/installations/445016e5-c428-4cf2-57c4-11f983dfc4aa/packages/bosh_vcloud_cpi/vendor/bundle/ruby/2.3.0/gems/rest-client-1.6.9/lib/restclient/abstract_response.rb:48:in `return!'\n/home/boshadmin/.bosh_init/installations/445016e5-c428-4cf2-57c4-11f983dfc4aa/packages/bosh_vcloud_cpi/lib/cloud/vcloud/vcd_client.rb:290:in `block (2 levels) in send_request'\n/home/boshadmin/.bosh_init/installations/445016e5-c428-4cf2-57c4-11f983dfc4aa/packages/bosh_vcloud_cpi/vendor/bundle/ruby/2.3.0/gems/rest-client-1.6.9/lib/restclient/request.rb:267:in `process_result'\n/home/boshadmin/.bosh_init/installations/445016e5-c428-4cf2-57c4-11f983dfc4aa/packages/bosh_vcloud_cpi/vendor/bundle/ruby/2.3.0/gems/rest-client-1.6.9/lib/restclient/request.rb:212:in `block in transmit'\n/home/boshadmin/.bosh_init/installations/445016e5-c428-4cf2-57c4-11f983dfc4aa/packages/ruby_vcloud_cpi/lib/ruby/2.3.0/net/http.rb:853:in `start'\
n/home/boshadmin/.bosh_init/installations/445016e5-c428-4cf2-57c4-11f983dfc4aa/packages/bosh_vcloud_cpi/vendor/bundle/ruby/2.3.0/gems/rest-client-1.6.9/lib/restclient/request.rb:206:in `transmit'\n/home/boshadmin/.bosh_init/installations/445016e5-c428-4cf2-57c4-11f983dfc4aa/packages/bosh_vcloud_cpi/vendor/bundle/ruby/2.3.0/gems/rest-client-1.6.9/lib/restclient/request.rb:68:in `execute'\n/home/boshadmin/.bosh_init/installations/445016e5-c428-4cf2-57c4-11f983dfc4aa/packages/bosh_vcloud_cpi/vendor/bundle/ruby/2.3.0/gems/rest-client-1.6.9/lib/restclient/request.rb:35:in `execute'\n/home/boshadmin/.bosh_init/installations/445016e5-c428-4cf2-57c4-11f983dfc4aa/packages/bosh_vcloud_cpi/lib/cloud/vcloud/vcd_client.rb:287:in `block in send_request'\n/home/boshadmin/.bosh_init/installations/445016e5-c428-4cf2-57c4-11f983dfc4aa/packages/bosh_vcloud_cpi/vendor/bundle/ruby/2.3.0/gems/bosh_common-1.3262.1/lib/common/retryable.rb:28:in `block in retryer'\n/home/boshadmin/.bosh_init/installations/4
45016e5-c428-4cf2-57c4-11f983dfc4aa/packages/bosh_vcloud_cpi/vendor/bundle/ruby/2.3.0/gems/bosh_common-1.3262.1/lib/common/retryable.rb:26:in `loop'\n/home/boshadmin/.bosh_init/installations/445016e5-c428-4cf2-57c4-11f983dfc4aa/packages/bosh_vcloud_cpi/vendor/bundle/ruby/2.3.0/gems/bosh_common-1.3262.1/lib/common/retryable.rb:26:in `retryer'\n/home/boshadmin/.bosh_init/installations/445016e5-c428-4cf2-57c4-11f983dfc4aa/packages/bosh_vcloud_cpi/vendor/bundle/ruby/2.3.0/gems/bosh_common-1.3262.1/lib/common/common.rb:119:in `retryable'\n/home/boshadmin/.bosh_init/installations/445016e5-c428-4cf2-57c4-11f983dfc4aa/packages/bosh_vcloud_cpi/lib/cloud/vcloud/vcd_client.rb:283:in `send_request'\n/home/boshadmin/.bosh_init/installations/445016e5-c428-4cf2-57c4-11f983dfc4aa/packages/bosh_vcloud_cpi/lib/cloud/vcloud/vcd_client.rb:126:in `invoke'\n/home/boshadmin/.bosh_init/installations/445016e5-c428-4cf2-57c4-11f983dfc4aa/packages/bosh_vcloud_cpi/lib/cloud/vcloud/steps/delete_catalog_media.rb
:14:in `block in perform'\n/home/boshadmin/.bosh_init/installations/445016e5-c428-4cf2-57c4-11f983dfc4aa/packages/bosh_vcloud_cpi/lib/cloud/vcloud/vcd_client.rb:198:in `timed_loop'\n/home/boshadmin/.bosh_init/installations/445016e5-c428-4cf2-57c4-11f983dfc4aa/packages/bosh_vcloud_cpi/lib/cloud/vcloud/steps/delete_catalog_media.rb:10:in `perform'\n/home/boshadmin/.bosh_init/installations/445016e5-c428-4cf2-57c4-11f983dfc4aa/packages/bosh_vcloud_cpi/lib/cloud/vcloud/steps.rb:37:in `next'\n/home/boshadmin/.bosh_init/installations/445016e5-c428-4cf2-57c4-11f983dfc4aa/packages/bosh_vcloud_cpi/lib/cloud/vcloud/cloud.rb:406:in `save_agent_env'\n/home/boshadmin/.bosh_init/installations/445016e5-c428-4cf2-57c4-11f983dfc4aa/packages/bosh_vcloud_cpi/lib/cloud/vcloud/cloud.rb:290:in `block (2 levels) in attach_disk'\n/home/boshadmin/.bosh_init/installations/445016e5-c428-4cf2-57c4-11f983dfc4aa/packages/bosh_vcloud_cpi/vendor/bundle/ruby/2.3.0/gems/bosh_common-1.3262.1/lib/common/retryable.rb:28
:in `block in retryer'\n/home/boshadmin/.bosh_init/installations/445016e5-c428-4cf2-57c4-11f983dfc4aa/packages/bosh_vcloud_cpi/vendor/bundle/ruby/2.3.0/gems/bosh_common-1.3262.1/lib/common/retryable.rb:26:in `loop'\n/home/boshadmin/.bosh_init/installations/445016e5-c428-4cf2-57c4-11f983dfc4aa/packages/bosh_vcloud_cpi/vendor/bundle/ruby/2.3.0/gems/bosh_common-1.3262.1/lib/common/retryable.rb:26:in `retryer'\n/home/boshadmin/.bosh_init/installations/445016e5-c428-4cf2-57c4-11f983dfc4aa/packages/bosh_vcloud_cpi/vendor/bundle/ruby/2.3.0/gems/bosh_common-1.3262.1/lib/common/common.rb:119:in `retryable'\n/home/boshadmin/.bosh_init/installations/445016e5-c428-4cf2-57c4-11f983dfc4aa/packages/bosh_vcloud_cpi/lib/cloud/vcloud/cloud.rb:279:in `block in attach_disk'\n/home/boshadmin/.bosh_init/installations/445016e5-c428-4cf2-57c4-11f983dfc4aa/packages/bosh_vcloud_cpi/lib/cloud/vcloud/steps.rb:44:in `block in perform'\n/home/boshadmin/.bosh_init/installations/445016e5-c428-4cf2-57c4-11f983dfc4a
a/packages/bosh_vcloud_cpi/vendor/bundle/ruby/2.3.0/gems/bosh_common-1.3262.1/lib/common/thread_formatter.rb:49:in `with_thread_name'\n/home/boshadmin/.bosh_init/installations/445016e5-c428-4cf2-57c4-11f983dfc4aa/packages/bosh_vcloud_cpi/lib/cloud/vcloud/steps.rb:41:in `perform'\n/home/boshadmin/.bosh_init/installations/445016e5-c428-4cf2-57c4-11f983dfc4aa/packages/bosh_vcloud_cpi/lib/cloud/vcloud/steps.rb:58:in `perform'\n/home/boshadmin/.bosh_init/installations/445016e5-c428-4cf2-57c4-11f983dfc4aa/packages/bosh_vcloud_cpi/lib/cloud/vcloud/cloud.rb:371:in `steps'\n/home/boshadmin/.bosh_init/installations/445016e5-c428-4cf2-57c4-11f983dfc4aa/packages/bosh_vcloud_cpi/lib/cloud/vcloud/cloud.rb:270:in `attach_disk'\n/home/boshadmin/.bosh_init/installations/445016e5-c428-4cf2-57c4-11f983dfc4aa/packages/bosh_vcloud_cpi/vendor/bundle/ruby/2.3.0/gems/bosh_cpi-1.3262.1/lib/bosh/cpi/cli.rb:71:in `public_send'\n/home/boshadmin/.bosh_init/installations/445016e5-c428-4cf2-57c4-11f983dfc4aa/pack
ages/bosh_vcloud_cpi/vendor/bundle/ruby/2.3.0/gems/bosh_cpi-1.3262.1/lib/bosh/cpi/cli.rb:71:in `run'\n/home/boshadmin/.bosh_init/installations/445016e5-c428-4cf2-57c4-11f983dfc4aa/packages/bosh_vcloud_cpi/bin/vcloud_cpi:31:in `<top (required)>'\n/home/boshadmin/.bosh_init/installations/445016e5-c428-4cf2-57c4-11f983dfc4aa/packages/ruby_vcloud_cpi/lib/ruby/gems/2.3.0/gems/bundler-1.12.4/lib/bundler/cli/exec.rb:63:in `load'\n/home/boshadmin/.bosh_init/installations/445016e5-c428-4cf2-57c4-11f983dfc4aa/packages/ruby_vcloud_cpi/lib/ruby/gems/2.3.0/gems/bundler-1.12.4/lib/bundler/cli/exec.rb:63:in `kernel_load'\n/home/boshadmin/.bosh_init/installations/445016e5-c428-4cf2-57c4-11f983dfc4aa/packages/ruby_vcloud_cpi/lib/ruby/gems/2.3.0/gems/bundler-1.12.4/lib/bundler/cli/exec.rb:24:in `run'\n/home/boshadmin/.bosh_init/installations/445016e5-c428-4cf2-57c4-11f983dfc4aa/packages/ruby_vcloud_cpi/lib/ruby/gems/2.3.0/gems/bundler-1.12.4/lib/bundler/cli.rb:304:in `exec'\n/home/boshadmin/.bosh_ini
t/installations/445016e5-c428-4cf2-57c4-11f983dfc4aa/packages/ruby_vcloud_cpi/lib/ruby/gems/2.3.0/gems/bundler-1.12.4/lib/bundler/vendor/thor/lib/thor/command.rb:27:in `run'\n/home/boshadmin/.bosh_init/installations/445016e5-c428-4cf2-57c4-11f983dfc4aa/packages/ruby_vcloud_cpi/lib/ruby/gems/2.3.0/gems/bundler-1.12.4/lib/bundler/vendor/thor/lib/thor/invocation.rb:126:in `invoke_command'\n/home/boshadmin/.bosh_init/installations/445016e5-c428-4cf2-57c4-11f983dfc4aa/packages/ruby_vcloud_cpi/lib/ruby/gems/2.3.0/gems/bundler-1.12.4/lib/bundler/vendor/thor/lib/thor.rb:359:in `dispatch'\n/home/boshadmin/.bosh_init/installations/445016e5-c428-4cf2-57c4-11f983dfc4aa/packages/ruby_vcloud_cpi/lib/ruby/gems/2.3.0/gems/bundler-1.12.4/lib/bundler/vendor/thor/lib/thor/base.rb:440:in `start'\n/home/boshadmin/.bosh_init/installations/445016e5-c428-4cf2-57c4-11f983dfc4aa/packages/ruby_vcloud_cpi/lib/ruby/gems/2.3.0/gems/bundler-1.12.4/lib/bundler/cli.rb:11:in `start'\n/home/boshadmin/.bosh_init/insta
llations/445016e5-c428-4cf2-57c4-11f983dfc4aa/packages/ruby_vcloud_cpi/lib/ruby/gems/2.3.0/gems/bundler-1.12.4/exe/bundle:27:in `block in <top (required)>'\n/home/boshadmin/.bosh_init/installations/445016e5-c428-4cf2-57c4-11f983dfc4aa/packages/ruby_vcloud_cpi/lib/ruby/gems/2.3.0/gems/bundler-1.12.4/lib/bundler/friendly_errors.rb:98:in `with_friendly_errors'\n/home/boshadmin/.bosh_init/installations/445016e5-c428-4cf2-57c4-11f983dfc4aa/packages/ruby_vcloud_cpi/lib/ruby/gems/2.3.0/gems/bundler-1.12.4/exe/bundle:19:in `<top (required)>'\n/home/boshadmin/.bosh_init/installations/445016e5-c428-4cf2-57c4-11f983dfc4aa/packages/ruby_vcloud_cpi/bin/bundle:22:in `load'\n/home/boshadmin/.bosh_init/installations/445016e5-c428-4cf2-57c4-11f983dfc4aa/packages/ruby_vcloud_cpi/bin/bundle:22:in `<main>'

This 500 server error on deletion of catalog item triggered the retry loop and thus indirectly caused the attach disk step to fail on subsequent attempts.

Any help on how to resolve this issue would be greatly appreciated.

Does anyone deploy Bosh/CF on vCloud Director and how is your experience with Bosh CPI for vCloud?

Thanks,
Phong

Join cf-bosh@lists.cloudfoundry.org to automatically receive all group messages.