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


Dmitriy Kalinin
 

majorErrorCode="500" message="[ d992ba15-cec3-4953-9af3-4132d6a111fd-e3c9
] Unable to perform this action. Contact your cloud administrator."
minorErrorCode="INTERNAL_SERVER_ERROR"
you might have to contact vcloud support to understand root cause of this
error.

On Fri, Apr 21, 2017 at 2:14 AM, Phong Tran <phong.tran(a)emc.com> wrote:

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/install
ations/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/retryab
le.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-11f
983dfc4a
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-11f983dfc
4aa/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_in
it/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.