cloudfoundry / bosh-vsphere-cpi-release

BOSH vSphere CPI
Apache License 2.0
31 stars 35 forks source link

`Address family not supported by protocol` on IPv6-enabled VCSAs #153

Closed cunnie closed 5 years ago

cunnie commented 6 years ago

Describe the bug

When uploading a stemcell to an IPv6-enabled VCSA, you may get an Address family not supported by protocol error

To Reproduce Steps to reproduce the behavior:

  1. Have a dual-stack VCSA
  2. Have an IPv4-only BOSH
  3. Upload a stemcell

CPI Error Log

Rescued Unknown: Address family not supported by protocol - Address family not supported by protocol - socket(2) for "vcenter-67.nono.io" port 443 (vcenter-67.nono.io:443). backtrace: /var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/vendor/bundle/ruby/2.4.0/gems/httpclient-2.8.3/lib/httpclient/session.rb:623:in `rescue in create_socket'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/vendor/bundle/ruby/2.4.0/gems/httpclient-2.8.3/lib/httpclient/session.rb:607:in `create_socket'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/vendor/bundle/ruby/2.4.0/gems/httpclient-2.8.3/lib/httpclient/ssl_socket.rb:21:in `create_socket'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/vendor/bundle/ruby/2.4.0/gems/httpclient-2.8.3/lib/httpclient/session.rb:752:in `block in connect'
/var/vcap/data/packages/ruby-2.4-r4/c8389dd95036a71df5213fafe665e7c72103dc00/lib/ruby/2.4.0/timeout.rb:93:in `block in timeout'
/var/vcap/data/packages/ruby-2.4-r4/c8389dd95036a71df5213fafe665e7c72103dc00/lib/ruby/2.4.0/timeout.rb:103:in `timeout'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/vendor/bundle/ruby/2.4.0/gems/httpclient-2.8.3/lib/httpclient/session.rb:748:in `connect'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/vendor/bundle/ruby/2.4.0/gems/httpclient-2.8.3/lib/httpclient/session.rb:511:in `query'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/vendor/bundle/ruby/2.4.0/gems/httpclient-2.8.3/lib/httpclient/session.rb:177:in `query'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/vendor/bundle/ruby/2.4.0/gems/httpclient-2.8.3/lib/httpclient.rb:1242:in `do_get_block'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/vendor/bundle/ruby/2.4.0/gems/httpclient-2.8.3/lib/httpclient.rb:1019:in `block in do_request'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/vendor/bundle/ruby/2.4.0/gems/httpclient-2.8.3/lib/httpclient.rb:1133:in `protect_keep_alive_disconnected'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/vendor/bundle/ruby/2.4.0/gems/httpclient-2.8.3/lib/httpclient.rb:1014:in `do_request'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/vendor/bundle/ruby/2.4.0/gems/httpclient-2.8.3/lib/httpclient.rb:856:in `request'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/vendor/bundle/ruby/2.4.0/gems/httpclient-2.8.3/lib/httpclient.rb:765:in `post'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/lib/cloud/vsphere/base_http_client.rb:76:in `do_request'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/lib/cloud/vsphere/base_http_client.rb:43:in `post'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/lib/ruby_vim_sdk/soap/stub_adapter.rb:25:in `invoke_method'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/lib/cloud/vsphere/sdk_helpers/retryable_stub_adapter.rb:46:in `block in invoke_method'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/lib/cloud/vsphere/retryer.rb:9:in `block in try'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/lib/cloud/vsphere/retryer.rb:8:in `times'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/lib/cloud/vsphere/retryer.rb:8:in `try'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/lib/cloud/vsphere/sdk_helpers/retryable_stub_adapter.rb:33:in `invoke_method'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/lib/ruby_vim_sdk/vmodl/managed_object.rb:13:in `invoke_method'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/lib/ruby_vim_sdk/vmodl/managed_object.rb:45:in `block (3 levels) in finalize'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/lib/ruby_vim_sdk/soap/stub_adapter.rb:55:in `invoke_property'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/lib/cloud/vsphere/sdk_helpers/retryable_stub_adapter.rb:85:in `invoke_property'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/lib/ruby_vim_sdk/vmodl/managed_object.rb:17:in `invoke_property'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/lib/ruby_vim_sdk/vmodl/managed_object.rb:30:in `block (3 levels) in finalize'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/lib/cloud/vsphere/vcenter_client.rb:23:in `initialize'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/lib/cloud/vsphere/cloud.rb:55:in `new'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/lib/cloud/vsphere/cloud.rb:55:in `initialize'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/lib/cloud/vsphere.rb:79:in `new'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/lib/cloud/vsphere.rb:79:in `initialize'
/var/vcap/packages/vsphere_cpi/bin/vsphere_cpi:37:in `new'
/var/vcap/packages/vsphere_cpi/bin/vsphere_cpi:37:in `block in <top (required)>'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/vendor/bundle/ruby/2.4.0/gems/bosh_cpi-2.4.1/lib/bosh/cpi/cli.rb:80:in `run'
/var/vcap/packages/vsphere_cpi/bin/vsphere_cpi:42:in `<top (required)>'
/var/vcap/data/packages/ruby-2.4-r4/c8389dd95036a71df5213fafe665e7c72103dc00/lib/ruby/site_ruby/2.4.0/bundler/cli/exec.rb:75:in `load'
/var/vcap/data/packages/ruby-2.4-r4/c8389dd95036a71df5213fafe665e7c72103dc00/lib/ruby/site_ruby/2.4.0/bundler/cli/exec.rb:75:in `kernel_load'
/var/vcap/data/packages/ruby-2.4-r4/c8389dd95036a71df5213fafe665e7c72103dc00/lib/ruby/site_ruby/2.4.0/bundler/cli/exec.rb:28:in `run'
/var/vcap/data/packages/ruby-2.4-r4/c8389dd95036a71df5213fafe665e7c72103dc00/lib/ruby/site_ruby/2.4.0/bundler/cli.rb:424:in `exec'
/var/vcap/data/packages/ruby-2.4-r4/c8389dd95036a71df5213fafe665e7c72103dc00/lib/ruby/site_ruby/2.4.0/bundler/vendor/thor/lib/thor/command.rb:27:in `run'
/var/vcap/data/packages/ruby-2.4-r4/c8389dd95036a71df5213fafe665e7c72103dc00/lib/ruby/site_ruby/2.4.0/bundler/vendor/thor/lib/thor/invocation.rb:126:in `invoke_command'
/var/vcap/data/packages/ruby-2.4-r4/c8389dd95036a71df5213fafe665e7c72103dc00/lib/ruby/site_ruby/2.4.0/bundler/vendor/thor/lib/thor.rb:387:in `dispatch'
/var/vcap/data/packages/ruby-2.4-r4/c8389dd95036a71df5213fafe665e7c72103dc00/lib/ruby/site_ruby/2.4.0/bundler/cli.rb:27:in `dispatch'
/var/vcap/data/packages/ruby-2.4-r4/c8389dd95036a71df5213fafe665e7c72103dc00/lib/ruby/site_ruby/2.4.0/bundler/vendor/thor/lib/thor/base.rb:466:in `start'
/var/vcap/data/packages/ruby-2.4-r4/c8389dd95036a71df5213fafe665e7c72103dc00/lib/ruby/site_ruby/2.4.0/bundler/cli.rb:18:in `start'
/var/vcap/packages/ruby-2.4-r4/bin/bundle:30:in `block in <main>'
/var/vcap/data/packages/ruby-2.4-r4/c8389dd95036a71df5213fafe665e7c72103dc00/lib/ruby/site_ruby/2.4.0/bundler/friendly_errors.rb:122:in `with_friendly_errors'
/var/vcap/packages/ruby-2.4-r4/bin/bundle:22:in `<main>'/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/lib/ruby_vim_sdk/vmomi_support.rb:56: warning: constant ::Fixnum is deprecated
I, [2018-09-24T15:29:25.863393 #12636]  INFO -- [req_id cpi-297143]: Starting info...
D, [2018-09-24T15:29:25.867674 #12636] DEBUG -- [req_id cpi-297143]: Running method 'RetrieveServiceContent'...
I, [2018-09-24T15:29:25.929591 #12636]  INFO -- [req_id cpi-297143]: Finished info in 0.07 seconds
Rescued Unknown: Address family not supported by protocol - Address family not supported by protocol - socket(2) for "vcenter-67.nono.io" port 443 (vcenter-67.nono.io:443). backtrace: /var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/vendor/bundle/ruby/2.4.0/gems/httpclient-2.8.3/lib/httpclient/session.rb:623:in `rescue in create_socket'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/vendor/bundle/ruby/2.4.0/gems/httpclient-2.8.3/lib/httpclient/session.rb:607:in `create_socket'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/vendor/bundle/ruby/2.4.0/gems/httpclient-2.8.3/lib/httpclient/ssl_socket.rb:21:in `create_socket'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/vendor/bundle/ruby/2.4.0/gems/httpclient-2.8.3/lib/httpclient/session.rb:752:in `block in connect'
/var/vcap/data/packages/ruby-2.4-r4/c8389dd95036a71df5213fafe665e7c72103dc00/lib/ruby/2.4.0/timeout.rb:93:in `block in timeout'
/var/vcap/data/packages/ruby-2.4-r4/c8389dd95036a71df5213fafe665e7c72103dc00/lib/ruby/2.4.0/timeout.rb:103:in `timeout'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/vendor/bundle/ruby/2.4.0/gems/httpclient-2.8.3/lib/httpclient/session.rb:748:in `connect'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/vendor/bundle/ruby/2.4.0/gems/httpclient-2.8.3/lib/httpclient/session.rb:511:in `query'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/vendor/bundle/ruby/2.4.0/gems/httpclient-2.8.3/lib/httpclient/session.rb:177:in `query'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/vendor/bundle/ruby/2.4.0/gems/httpclient-2.8.3/lib/httpclient.rb:1242:in `do_get_block'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/vendor/bundle/ruby/2.4.0/gems/httpclient-2.8.3/lib/httpclient.rb:1019:in `block in do_request'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/vendor/bundle/ruby/2.4.0/gems/httpclient-2.8.3/lib/httpclient.rb:1133:in `protect_keep_alive_disconnected'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/vendor/bundle/ruby/2.4.0/gems/httpclient-2.8.3/lib/httpclient.rb:1014:in `do_request'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/vendor/bundle/ruby/2.4.0/gems/httpclient-2.8.3/lib/httpclient.rb:856:in `request'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/vendor/bundle/ruby/2.4.0/gems/httpclient-2.8.3/lib/httpclient.rb:765:in `post'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/lib/cloud/vsphere/base_http_client.rb:76:in `do_request'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/lib/cloud/vsphere/base_http_client.rb:43:in `post'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/lib/ruby_vim_sdk/soap/stub_adapter.rb:25:in `invoke_method'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/lib/cloud/vsphere/sdk_helpers/retryable_stub_adapter.rb:46:in `block in invoke_method'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/lib/cloud/vsphere/retryer.rb:9:in `block in try'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/lib/cloud/vsphere/retryer.rb:8:in `times'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/lib/cloud/vsphere/retryer.rb:8:in `try'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/lib/cloud/vsphere/sdk_helpers/retryable_stub_adapter.rb:33:in `invoke_method'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/lib/ruby_vim_sdk/vmodl/managed_object.rb:13:in `invoke_method'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/lib/ruby_vim_sdk/vmodl/managed_object.rb:45:in `block (3 levels) in finalize'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/lib/ruby_vim_sdk/soap/stub_adapter.rb:55:in `invoke_property'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/lib/cloud/vsphere/sdk_helpers/retryable_stub_adapter.rb:85:in `invoke_property'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/lib/ruby_vim_sdk/vmodl/managed_object.rb:17:in `invoke_property'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/lib/ruby_vim_sdk/vmodl/managed_object.rb:30:in `block (3 levels) in finalize'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/lib/cloud/vsphere/vcenter_client.rb:23:in `initialize'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/lib/cloud/vsphere/cloud.rb:55:in `new'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/lib/cloud/vsphere/cloud.rb:55:in `initialize'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/lib/cloud/vsphere.rb:79:in `new'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/lib/cloud/vsphere.rb:79:in `initialize'
/var/vcap/packages/vsphere_cpi/bin/vsphere_cpi:37:in `new'
/var/vcap/packages/vsphere_cpi/bin/vsphere_cpi:37:in `block in <top (required)>'
/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/vendor/bundle/ruby/2.4.0/gems/bosh_cpi-2.4.1/lib/bosh/cpi/cli.rb:80:in `run'
/var/vcap/packages/vsphere_cpi/bin/vsphere_cpi:42:in `<top (required)>'
/var/vcap/data/packages/ruby-2.4-r4/c8389dd95036a71df5213fafe665e7c72103dc00/lib/ruby/site_ruby/2.4.0/bundler/cli/exec.rb:75:in `load'
/var/vcap/data/packages/ruby-2.4-r4/c8389dd95036a71df5213fafe665e7c72103dc00/lib/ruby/site_ruby/2.4.0/bundler/cli/exec.rb:75:in `kernel_load'
/var/vcap/data/packages/ruby-2.4-r4/c8389dd95036a71df5213fafe665e7c72103dc00/lib/ruby/site_ruby/2.4.0/bundler/cli/exec.rb:28:in `run'
/var/vcap/data/packages/ruby-2.4-r4/c8389dd95036a71df5213fafe665e7c72103dc00/lib/ruby/site_ruby/2.4.0/bundler/cli.rb:424:in `exec'
/var/vcap/data/packages/ruby-2.4-r4/c8389dd95036a71df5213fafe665e7c72103dc00/lib/ruby/site_ruby/2.4.0/bundler/vendor/thor/lib/thor/command.rb:27:in `run'
/var/vcap/data/packages/ruby-2.4-r4/c8389dd95036a71df5213fafe665e7c72103dc00/lib/ruby/site_ruby/2.4.0/bundler/vendor/thor/lib/thor/invocation.rb:126:in `invoke_command'
/var/vcap/data/packages/ruby-2.4-r4/c8389dd95036a71df5213fafe665e7c72103dc00/lib/ruby/site_ruby/2.4.0/bundler/vendor/thor/lib/thor.rb:387:in `dispatch'
/var/vcap/data/packages/ruby-2.4-r4/c8389dd95036a71df5213fafe665e7c72103dc00/lib/ruby/site_ruby/2.4.0/bundler/cli.rb:27:in `dispatch'
/var/vcap/data/packages/ruby-2.4-r4/c8389dd95036a71df5213fafe665e7c72103dc00/lib/ruby/site_ruby/2.4.0/bundler/vendor/thor/lib/thor/base.rb:466:in `start'
/var/vcap/data/packages/ruby-2.4-r4/c8389dd95036a71df5213fafe665e7c72103dc00/lib/ruby/site_ruby/2.4.0/bundler/cli.rb:18:in `start'
/var/vcap/packages/ruby-2.4-r4/bin/bundle:30:in `block in <main>'
/var/vcap/data/packages/ruby-2.4-r4/c8389dd95036a71df5213fafe665e7c72103dc00/lib/ruby/site_ruby/2.4.0/bundler/friendly_errors.rb:122:in `with_friendly_errors'
/var/vcap/packages/ruby-2.4-r4/bin/bundle:22:in `<main>'/var/vcap/data/packages/vsphere_cpi/7a1eae0465f2b7c54d1be43377919165a49dd9f7/lib/ruby_vim_sdk/vmomi_support.rb:56: warning: constant ::Fixnum is deprecated
I, [2018-09-24T15:29:39.295966 #12645]  INFO -- [req_id cpi-920945]: Starting info...
D, [2018-09-24T15:29:39.308005 #12645] DEBUG -- [req_id cpi-920945]: Running method 'RetrieveServiceContent'...
I, [2018-09-24T15:29:39.545847 #12645]  INFO -- [req_id cpi-920945]: Finished info in 0.25 seconds

Expected behavior

I'd expect the stemcell to be uploaded

Screenshots If applicable, add screenshots to help explain your problem.

Release Version & Related Info (please complete the following information):

Additional context Add any other context about the problem here.

EleanorRigby commented 6 years ago

Is IPv6 support enabled on the esxi hosts?

cunnie commented 6 years ago

@EleanorRigby Yes, IPv6 is enabled on the ESXi hosts and on the vCenter 6.7 — all the cool kids are using IPv6 these days. :wink: [edited for clarity]

dig +short any esxi-0.nono.io
2601:646:100:69f0::40
10.0.9.40
cunnie commented 5 years ago

This is in regards to @nehagjain15 's question:

Why does this problem occur after the BOSH director has already been deployed — the BOSH CLI uses the same vSphere CPI as the Director, so I would expect the error to occur during the deployment of the BOSH director, not later during the deployment of PAS.

The answer may lie in that the failure occurs in the info CPI method:

Task 9 | 11:06:09 | Error: Unknown CPI error 'Unknown' with message 'Address family not supported by protocol - Address family not supported by protocol - socket(2) for "vcenter-67.nono.io" port 443 (vcenter-67.nono.io:443)' in 'info' CPI method (CPI request ID: 'cpi-842767')Task 9 | 11:06:09 | Error: Unknown CPI error 'Unknown' with message 'Address family not supported by protocol - Address family not supported by protocol - socket(2) for "vcenter-67.nono.io" port 443 (vcenter-67.nono.io:443)' in 'info' CPI method (CPI request ID: 'cpi-842767')

But the BOSH CLI never calls the info method; here are the list of calls the BOSH CLI made to the vSphere CPI during the deployment of the BOSH Director:

{"method":"create_stemcell","arguments":["/home/tempest-web/.bosh/installations/bd6289cb-4fda-4f2d-4f3d-52c4d1a1179a/tmp/stemcell-manager634576359/image",{"architecture":"x86_64","container_format":"bare","disk":3072,"disk_format":"ovf","hypervisor":"esxi","infrastructure":"vsphere","name":"bosh-vsphere-esxi-ubuntu-xenial-go_agent","os_distro":"ubuntu","os_type":"linux","root_device_name":"/dev/sda1","version":"97.15"}],"context":{"director_uuid":"4f9103cb-6f71-4f1e-5ab3-4d84d9a17138"}}
{"method":"create_vm","arguments":["9075df22-b131-42fa-787a-5901c8b2f9cb","sc-17119a39-e6e3-474b-85b6-1e233610ee4b",{"cpu":2,"datacenters":[{"clusters":[{"cl":{"resource_pool":"om"}}],"name":"dc"}],"disk":51200,"ram":8192},{"PAS":{"cloud_properties":{"name":"PAS"},"default":["dns","gateway"],"dns":["8.8.8.8"],"gateway":"10.0.250.1","ip":"10.0.250.2","netmask":"255.255.255.0","type":"manual"}},[],{"bosh":{"mbus":{"cert":{"certificate":"-----BEGIN CERTIFICATE-----\nMIIDdjCCAl6gAwIBAgIUJQQ20FwAQp2uGrbzM8K4xVjoNDQwDQYJKoZIhvcNAQEL\nBQAwHzELMAkGA1UEBhMCVVMxEDAOBgNVBAoMB1Bpdm90YWwwHhcNMTgwOTExMTg0\nNjMxWhcNMjAwOTExMTg0NjMxWjA0MQswCQYDVQQGEwJVUzEQMA4GA1UECgwHUGl2\nb3RhbDETMBEGA1UEAwwKMTAuMC4yNTAuMjCCASIwDQYJKoZIhvcNAQEBBQADggEP\nADCCAQoCggEBAOcwPwccpcoyfgKSgZawdTKPtf6nmSrQeOn+q3o1gGKqus5ngV5w\nqas7kMtpXstzMkuMJmXaAUAmqSzLeyDmWgGbCzG/Is67VNM2vT7Kqpb0oHR4bZYV\nbi0QvGRIi9U7Y/X6j94bKGcnapaZq50GAX2E7eeTd5+FFwPVeA5OpOsVZd+Xg3vO\nphR5rE58x+sqSEdXgsS+6IVxAbsif9OdaUZtIMlDu/oC7/UH6ffohdQ7l5zbjIxI\n6u/V+CLaJyqOUWbzrh993eQY/ecghjDY3COWnJJLvxkyaDf0K+0QqZOrKX+FrI6U\nqUDz/n+t59FnjdrAzbSGcIyM/nnJYCF4k4ECAwEAAaOBlDCBkTAdBgNVHQ4EFgQU\nJ4od1RtudEHEJ3PGkrl9PRp8J6EwHwYDVR0jBBgwFoAUQtQjZ9ulFAH/5tnBwkl9\nQtbIJUwwHQYDVR0lBBYwFAYIKwYBBQUHAwIGCCsGAQUFBwMBMA4GA1UdDwEB/wQE\nAwIHgDAgBgNVHREEGTAXhwQKAPoCgglsb2NhbGhvc3SHBH8AAAEwDQYJKoZIhvcN\nAQELBQADggEBAAlhbeiWAa/QrQASSN6bqZlXCI6LLR6z3qStwAGfbrCoVcuMU47A\nxRhdPC5e/JshfNnB3DzX2os2igbIdmmCDNQEVH7A4a5a9nJEvhbK5NpeZC25yMVQ\nnb6hm9YUzLGWOEcvorqY8jB1GGRYfFPXpxgRuwndcSn4FfG5lDeqhP8VUjyVtp6W\nW0cnsHgeiPkIZpgma54jmKmUiNH3Zxooz1c05UEdIr8TneLGZlR++BYsR6kwSVE7\nHTsu/D2fLHrQwt4pQOPtFuc1jP+HcoqulhiJx164TBAmfWbNssliCkiqciV21v4e\nnwXkMCr2ynyy+QXb/qLyMZZKPqyKFA1ipvU=\n-----END CERTIFICATE-----\n","private_key":"-----BEGIN RSA PRIVATE KEY-----\nMIIEpAIBAAKCAQEA5zA/BxylyjJ+ApKBlrB1Mo+1/qeZKtB46f6rejWAYqq6zmeB\nXnCpqzuQy2ley3MyS4wmZdoBQCapLMt7IOZaAZsLMb8izrtU0za9PsqqlvSgdHht\nlhVuLRC8ZEiL1Ttj9fqP3hsoZydqlpmrnQYBfYTt55N3n4UXA9V4Dk6k6xVl35eD\ne86mFHmsTnzH6ypIR1eCxL7ohXEBuyJ/051pRm0gyUO7+gLv9Qfp9+iF1DuXnNuM\njEjq79X4ItonKo5RZvOuH33d5Bj95yCGMNjcI5ackku/GTJoN/Qr7RCpk6spf4Ws\njpSpQPP+f63n0WeN2sDNtIZwjIz+eclgIXiTgQIDAQABAoIBAAiNCEfDD37DD1YZ\nBSIFtNAB8MFSgZ/Lxi0hdkY25GDB39byjR5pHF1w/pIHe7IauKmCrYjm31T4GRnH\nDO7SllGo4mkcoLT0yNZnF+jSpiyfL7AfJC6A7GpOTCmJZWKlp7TZZ6jXaE8obhDT\n7j0Ik9WIrSP7mFkWGxvRMXeWAROQzQw29AX5TGy5Cje9rDgfykPR5Yfc0vFKW1CS\njkPGCHV+P7l94dVeSqY19GCA9/tyG/zW/WBvi0//yxdxNPimb5znOHB+JFYWXAyO\nXPCCNK6+FXdwka05ajD1jkXKNbVF7YIQ2JuiWQqvDoSUhU5v7kHi8+WfRUpQ/8QU\nbfFNH2ECgYEA9vTGvULhtyaGIrzmHe8PLZiiq1NpBWN+kuTPtTv9fzqjk9eLpQTE\nZk4p6jr/gjS2AFlkVSd1tHhMtYmhY6CaGC/ovcugrVaRjXL2HroWiwh+u4iyjlOY\nKTmCMWXVprciNAeN6N1+w7n2QUd/fTPh7qhFKwrooZuG9aoiiepiGXMCgYEA76el\nqPnXjtJWgDFIhDKZlaeCAYBLc86WsvanZxKGHua/tK5hj27k+mQOup7GUpN4+jnb\nhgdeOQzAsjQ5/Mt+wbvQE9fQ2e2PqZkV+A7ts9tvTXG6BepzcW+vvH+TWsi3+oni\nXCSFxbw1X+XoF4EWcjn1iGkSGEdh6CtNEMB68jsCgYEAs0aO3+Ylpae5yI4JH8Hj\n6t3beTRcESVhRZIFlzOtmyceiLz5Cxqi2QH1O60Iv6U0WpyKUacLs6+BQGhhWMnG\nE7jz5JRmWG93yo+iTDwbEWNhXRKnTNsyovq0oNekehqIIe05/8qLs9rUAh+9VU7M\nvUw6qjyJFIirOLwBxsz32jECgYBl9HOEnK24xAEqzkykeQZf5YBodRUkcmooPsjf\nD8FhWheKnXlB1RKy92hQuoVy0exwv7aFoZLTQHqmFZPp2QTXFLikCHeAjxFEPK1c\n97TmhF8omk5if+iXBMXFspyUzbl/a7OSMbN7eONYJe4EOdW7yK6NVu3syEl9xRYn\nH0vuywKBgQC/d8uzHx7TgimzG3Ab3bag6mtCnXyv1gx33XS6tPn7RRNar8sh8Fsu\n+rgPTuD1xT2z8pQuchAhjhv23SyI0jbLlRbMrMlXZ0qkraXkgDXb5h9iBj91viDh\nrOWslOJ1AMHWS7LTAzevjyrhV/zlU/kYhpeiJdj5Vh6KLDwJ8MxLbA==\n-----END RSA PRIVATE KEY-----\n"}},"password":"$6$03db9974a34ac148$GRvWMO1uhwybZtOC5xocMr0EMLQ5kyXp/DLJ7uzdx68W/nU4ImgjluEscGWEXgw2CxMD4roeghMlqJSOh5LAq."}}],"context":{"director_uuid":"4f9103cb-6f71-4f1e-5ab3-4d84d9a17138"}}
{"method":"set_vm_metadata","arguments":["vm-ff2720d5-f1df-459a-ae8b-2936cd75cec6",{"created_at":"2018-09-25T01:00:20Z","deployment":"p-bosh","director":"bosh-init","index":"0","instance_group":"bosh","job":"bosh"}],"context":{"director_uuid":"4f9103cb-6f71-4f1e-5ab3-4d84d9a17138"}}
{"method":"create_disk","arguments":[51200,{"type":"thin"},"vm-ff2720d5-f1df-459a-ae8b-2936cd75cec6"],"context":{"director_uuid":"4f9103cb-6f71-4f1e-5ab3-4d84d9a17138"}}
{"method":"attach_disk","arguments":["vm-ff2720d5-f1df-459a-ae8b-2936cd75cec6","disk-6b9371cd-3ebf-404b-a0e4-a51bd9b3ade5"],"context":{"director_uuid":"4f9103cb-6f71-4f1e-5ab3-4d84d9a17138"}}
{"method":"set_disk_metadata","arguments":["disk-6b9371cd-3ebf-404b-a0e4-a51bd9b3ade5",{"attached_at":"2018-09-25T01:01:35Z","deployment":"p-bosh","director":"bosh-init","instance_group":"bosh","instance_index":"0"}],"context":{"director_uuid":"4f9103cb-6f71-4f1e-5ab3-4d84d9a17138"}}

Here is complete the BOSH log (BOSH_LOG_LEVEL=debug) of the BOSH CLI's deployment of the BOSH Director (with passwords redacted).

cunnie commented 5 years ago

This is a very simple way to cause the failure (run this command on the BOSH Director):

echo '{"method":"info","arguments":[],"context":{"director_uuid":"blah"}}' |
  PATH=/var/vcap/packages/ruby-2.4-r4/bin:/var/vcap/packages/iso9660wrap/bin:$PATH \
  BUNDLE_GEMFILE=/var/vcap/packages/vsphere_cpi/Gemfile \
  /var/vcap/packages/ruby-2.4-r4/bin/bundle exec \
  /var/vcap/packages/vsphere_cpi/bin/vsphere_cpi \
  /var/vcap/jobs/vsphere_cpi/config/cpi.json

And here is.a similar command to run on the Operations Manager:

echo '{"method":"info","arguments":[],"context":{"director_uuid":"blah"}}' |
  BUNDLE_GEMFILE=$(echo /home/tempest-web/.bosh/installations/*/packages/vsphere_cpi/Gemfile) \
  /home/tempest-web/.bosh/installations/*/packages/ruby-2.4-r4/bin/bundle exec \
  /home/tempest-web/.bosh/installations/*/packages/vsphere_cpi/bin/vsphere_cpi \
  FIND-THE-CPI-JSON-FILE
nehagjain15 commented 5 years ago

@cunnie The error that you are seeing is raised when vcenter_client is being initialized and during the deployment of director each of the method that you have listed does that successfully. It is just that when the call is made from deployed director vm an error is being raised. So, I am not sure if thats where the problem is. We will try to do the same setup and will update you on how it goes.

cunnie commented 5 years ago

The error does not exhibit on the Ops Manager when invoked with the same cpi.json file as the BOSH Director's:

echo '{"method":"info","arguments":[],"context":{"director_uuid":"blah"}}' |
  BUNDLE_GEMFILE=$(echo /home/tempest-web/.bosh/installations/*/packages/vsphere_cpi/Gemfile) \
  /home/tempest-web/.bosh/installations/*/packages/ruby-2.4-r4/bin/bundle exec \
  /home/tempest-web/.bosh/installations/*/packages/vsphere_cpi/bin/vsphere_cpi \
  ~/cpi.json
/home/tempest-web/.bosh/installations/bd6289cb-4fda-4f2d-4f3d-52c4d1a1179a/packages/vsphere_cpi/lib/ruby_vim_sdk/vmomi_support.rb:56: warning: constant ::Fixnum is deprecated
I, [2018-09-28T14:51:56.471096 #31714]  INFO -- [req_id ]: Starting info...
D, [2018-09-28T14:51:56.473548 #31714] DEBUG -- : Running method 'RetrieveServiceContent'...
D, [2018-09-28T14:51:56.575536 #31714] DEBUG -- : Running method 'Login'...
I, [2018-09-28T14:51:56.753872 #31714]  INFO -- [req_id ]: Finished info in 0.28 seconds
{"result":{"stemcell_formats":["vsphere-ovf","vsphere-ova"]},"error":null,"log":""}D, [2018-09-28T14:51:56.755447 #31714] DEBUG -- : Running method 'Logout'...
cunnie commented 5 years ago

I believe I can make the error appear on the OpsMgr by moving the OpsMgr to an IPv4 subnet which is not shared by the vcenter. I'll run the test during lunch.

My hypothesis is as follows:

I believe that this behavior is caused by the IPv6 address being returned when the VM is not in the same subnet as the vcenter.

cunnie commented 5 years ago

Workaround: use vCenter IPv4 address not hostname in BOSH manifest

Short version: if

EleanorRigby commented 5 years ago

@cunnie : Thanks for clear triage of the issue. Do you think CPI can change any source code to reflect this? or this is mostly for documentation and clarity?

cunnie commented 5 years ago

I'm closing this issue because there's a workaround.

cunnie commented 5 years ago

Addendum: a similar error may show up with an IPv4 Director and a dual-stack ESXi host:

Task 751 | 11:44:36 | Creating missing vms: worker/d878cec9-14a9-4aaf-a55f-e5b890379518 (0) (00:00:16)
                    L Error: Unknown CPI error 'Unknown' with message 'Address family not supported by protocol - Address family not supported by protocol - socket(2) for "esxi-2.nono.io" port 443 (esxi-2.nono.io:443)' in 'create_vm' CPI method (CPI request ID: 'cpi-604442')

When this happens, make sure that the BOSH Director can reach the ESXi host over the IPv4 network (i.e. that there's no firewall rule blocking it). In my case, I had a firewall rule blocking the Director's subnet (10.2.0.0/24) from reaching the vSphere subnet (10.0.9.0/24) with exceptions for the Director to reach the vCenter and two ESXi hosts. Adding an exception for the Director to reach the newly-added third ESXi host (esxi-2.nono.io) fixed the problem for me.

Hostname IP Addr
bosh-vsphere.nono.io 10.2.0.250
73.189.219.4
esxi-2.nono.io 10.0.9.42
2601:646:0100:69f0::42