Pivotal Knowledge Base

Follow

Bosh deployment reports unknown CPI error 'execution expired'

Environment

Product Version
Pivotal Cloud Foundry (PCF) 1.7
vSphere CPI 26

Symptom

Deploying Ops manager director is successful but deployment of Elastic Run Time fails with the following error during 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'

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 exception thrown by ruby timeout module which reads "execution expired". This means The ruby httpclient did not receive a response from vcenter 

Resolution

To workaround this problem have customer use a different datastore for vm creation to ensure all VMWARE api calls are successful from the bosh director VM. Customer 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 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 and 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 

 

Comments

Powered by Zendesk