Pivotal Cloud Foundry - BOSH Deployment Reports Unknown CPI Error 'execution expired'
search cancel

Pivotal Cloud Foundry - BOSH Deployment Reports Unknown CPI Error 'execution expired'

book

Article ID: 297708

calendar_today

Updated On:

Products

VMware Tanzu Application Service for VMs

Issue/Introduction

Symptoms:

Deploying Operations (Ops) Manager Director is successful but the deployment of Pivotal Application Service fails with the following error during virtual machine (VM) creation.

Error Message:

ERROR -- DirectorJobRunner: error creating vm: Unknown CPI error 'Unknown' with message 'execution expired'

Full Stack Trace:

I, [2016-08-29T14:59:46.930028 #15357]  INFO -- : execution expired - /var/vcap/packages/vsphere_cpi_ruby/lib/ruby/2.1.0/openssl/buffering.rb:61:in `sysread'
/var/vcap/packages/vsphere_cpi_ruby/lib/ruby/2.1.0/openssl/buffering.rb:61:in `fill_rbuff'
/var/vcap/packages/vsphere_cpi_ruby/lib/ruby/2.1.0/openssl/buffering.rb:208:in `gets'
/var/vcap/packages/vsphere_cpi/vendor/bundle/ruby/2.1.0/gems/httpclient-2.7.1/lib/httpclient/ssl_socket.rb:74:in `gets'
/var/vcap/packages/vsphere_cpi/vendor/bundle/ruby/2.1.0/gems/httpclient-2.7.1/lib/httpclient/session.rb:792:in `block in parse_header'
/var/vcap/packages/vsphere_cpi_ruby/lib/ruby/2.1.0/timeout.rb:90:in `block in timeout'
/var/vcap/packages/vsphere_cpi_ruby/lib/ruby/2.1.0/timeout.rb:100:in `call'
/var/vcap/packages/vsphere_cpi_ruby/lib/ruby/2.1.0/timeout.rb:100:in `timeout'
/var/vcap/packages/vsphere_cpi/vendor/bundle/ruby/2.1.0/gems/httpclient-2.7.1/lib/httpclient/session.rb:788:in `parse_header'
/var/vcap/packages/vsphere_cpi/vendor/bundle/ruby/2.1.0/gems/httpclient-2.7.1/lib/httpclient/session.rb:771:in `read_header'
/var/vcap/packages/vsphere_cpi/vendor/bundle/ruby/2.1.0/gems/httpclient-2.7.1/lib/httpclient/session.rb:547:in `get_header'
/var/vcap/packages/vsphere_cpi/vendor/bundle/ruby/2.1.0/gems/httpclient-2.7.1/lib/httpclient.rb:1294:in `do_get_header'
/var/vcap/packages/vsphere_cpi/vendor/bundle/ruby/2.1.0/gems/httpclient-2.7.1/lib/httpclient.rb:1241:in `do_get_block'
/var/vcap/packages/vsphere_cpi/vendor/bundle/ruby/2.1.0/gems/httpclient-2.7.1/lib/httpclient.rb:1021:in `block in do_request'
/var/vcap/packages/vsphere_cpi/vendor/bundle/ruby/2.1.0/gems/httpclient-2.7.1/lib/httpclient.rb:1129:in `protect_keep_alive_disconnected'
/var/vcap/packages/vsphere_cpi/vendor/bundle/ruby/2.1.0/gems/httpclient-2.7.1/lib/httpclient.rb:1016:in `do_request'
/var/vcap/packages/vsphere_cpi/vendor/bundle/ruby/2.1.0/gems/httpclient-2.7.1/lib/httpclient.rb:858:in `request'
/var/vcap/packages/vsphere_cpi/vendor/bundle/ruby/2.1.0/gems/httpclient-2.7.1/lib/httpclient.rb:771:in `put'
/var/vcap/packages/vsphere_cpi/lib/cloud/vsphere/file_provider.rb:32:in `block in upload_file'
/var/vcap/packages/vsphere_cpi/lib/cloud/vsphere/retry_block.rb:9:in `block in retry_block'
/var/vcap/packages/vsphere_cpi/lib/cloud/vsphere/retry_block.rb:7:in `times'
/var/vcap/packages/vsphere_cpi/lib/cloud/vsphere/retry_block.rb:7:in `retry_block'
/var/vcap/packages/vsphere_cpi/lib/cloud/vsphere/file_provider.rb:28:in `upload_file'
/var/vcap/packages/vsphere_cpi/lib/cloud/vsphere/agent_env.rb:34:in `set_env'
/var/vcap/packages/vsphere_cpi/lib/cloud/vsphere/vm_creator.rb:106:in `create'
/var/vcap/packages/vsphere_cpi/lib/cloud/vsphere/cloud.rb:185:in `block in create_vm'
/var/vcap/packages/vsphere_cpi/vendor/bundle/ruby/2.1.0/gems/bosh_common-1.3181.0/lib/common/thread_formatter.rb:49:in `with_thread_name'
/var/vcap/packages/vsphere_cpi/lib/cloud/vsphere/cloud.rb:160:in `create_vm'
/var/vcap/packages/vsphere_cpi_ruby/lib/ruby/2.1.0/forwardable.rb:183:in `create_vm'
/var/vcap/packages/vsphere_cpi/vendor/bundle/ruby/2.1.0/gems/bosh_cpi-1.3181.0/lib/bosh/cpi/cli.rb:70:in `public_send'
/var/vcap/packages/vsphere_cpi/vendor/bundle/ruby/2.1.0/gems/bosh_cpi-1.3181.0/lib/bosh/cpi/cli.rb:70:in `run'
/var/vcap/packages/vsphere_cpi/bin/vsphere_cpi:37:in `'
, exit_status: pid 15347 exit 0
E, [2016-08-29 14:59:48 #14573] [create_missing_vm(doppler-partition-b0eed9d95310d7b95e45/0 (71f72b8b-472d-4474-984a-1f4ebb0fb8d8)/18)] ERROR -- DirectorJobRunner: error creating vm: Unknown CPI error 'Unknown' with message 'execution expired'
E, [2016-08-29 14:59:48 #14573] [] ERROR -- DirectorJobRunner: Worker thread raised exception: Unknown CPI error 'Unknown' with message 'execution expired' - /var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_cpi-1.3255.0/lib/cloud/external_cpi.rb:108:in `handle_error'

Environment


Cause

This is a timeout error that occurs when BOSH attempts to upload two small files in the datastore where the newly created virtual machine resides. The key error here is an exception thrown by the Ruby timeout module which reads "execution expired". This means the Ruby "httpclient" did not receive a response from vCenter.

 

Resolution

To resolve, this issue customer should use a different datastore for vm creation to ensure all VMware API calls are successful from the BOSH director VM. Customers could also try to delete and recreate the datastore in question and see if that resolves the file upload issues

Troubleshooting Tips

Here is the GitHub code reference that performs an API call to the upload of env.json and env.iso for each VM created by the BOSH director

We can simulate this behavior an perform a isolated upload test using curl and probe which datastores are having file upload issues.

The following variables and curl command is just here as a reference to help you build a similar command to use in your environment

  • DOMAIN: Domain name vCenter user resides in
  • USER: vCenter username
  • PASSWORD: password for vCenter user
  • VCENTER_HOST: ip or hostname of vCenter server
  • DCPATH: Name of datacenter datastore resides in
  • DSNAME: name of datastore file will be uploaded to

Note: The filename test-env-1234567890.json has all "-" characters converted to "%2d" as the url needs to be properly encoded as per RFC-3986

 curl -k -u "${DOMAIN}\${USER}:${PASSWORD}" -v --data-binary @./test-env-1234567890.json -X PUT "https://${VCENTER_HOST}/folder/test/test%2denv%2d1234567890.json?dcPath=${DCPATH}&dsName=${DSNAME}"
 

Here is an example of putting the above command in practice. We upload test-env-1234567890.json to Datacenter called cluster1 in datastore called datastore1 in path /test

  1. First create a directory or choose an existing directory in the VMware datastore. In this example we use /test directory
  2. Create a file or use and existing file. For this example we use test-env-1234567890.json
  3. ssh into BOSH director VM
  4. Example of curl command for successful upload of file 
    $ curl -k -u "vsphere.local\user:password" -v --data-binary @./test-env-1234567890.json -X PUT "https://172.16.0.5/folder/test/test%2denv%2d1234567890.json?dcPath=cluster1&dsName=datastore1"
* Hostname was NOT found in DNS cache
* Trying 172.16.0.5...
* Connected to 172.16.0.5 (172.16.0.5) port 443 (#0)
* successfully set certificate verify locations:
* CAfile: none
CApath: /etc/ssl/certs
* SSLv3, TLS handshake, Client hello (1):
.
. *SSL output omitted*
.
* Server auth using Basic with user 'vsphere.local\user'
> PUT /folder/test/test%2denv%2d1234567890.json?dcPath=cluster1&dsName=datastore1 HTTP/1.1
> Authorization: Basic dnNwaGVyZS5sb2NhbFxlbnYzdXNlcjo4YXk5Ym1mNENiSk9XaTIh
> User-Agent: curl/7.35.0
> Host: 172.16.0.5
> Accept: /
> Content-Length: 10
> Content-Type: application/x-www-form-urlencoded
> 
* upload completely sent off: 10 out of 10 bytes
< HTTP/1.1 201 Created
< Date: Wed, 31 Aug 2016 16:04:48 GMT
< Set-Cookie: vmware_soap_session="14ebfccbfe5ea25cd67956a59a096a094f0274ff"; Path=/; HttpOnly; Secure; 
< Connection: close
< Content-Type: text; charset=plain
< X-Frame-Options: DENY
< Content-Length: 0
< 
* Closing connection 0
* SSLv3, TLS alert, Client hello (1):
  5. The following message observed above confirms the file upload was successful. But to verify you should use the VMware datastore browser to confirm file was uploaded successfully. 
    upload completely sent off: 10 out of 10 bytes


Powered by Wolken Software