Working around vSphere VAPI request rejected errors


This morning I bumped into a weird issue while attempting to provision some new VMs with the terraform vsphere provider. After reviewing my plan I tried to apply the changes and was greeted with the following error:

$ terraform apply kubernetes-worker-additions-plan

Error: Error refreshing state: 1 error(s) occurred:

* provider.vsphere: Error connecting to CIS REST endpoint: Login failed: body: {"type":"com.vmware.vapi.std.errors.service_unavailable","value":{"messages":[{"args":[],"default_message":"Request rejected due to high request rate. Try again later.","id":"com.vmware.vapi.endpoint.highRequestRate"}]}}, status: 503 Service Unavailable

I’ve performed this operation 100s of times in the past and this is the first time I’ve encountered this error. To see what was going on I SSH’ed into my vcenter appliance and poked around the VAPI endpoint logs in /var/log/vmware/vapi/endpoint. The logs contained dozens of GC Allocation Failures:

2018-02-03T15:28:17.547+0000: 16.738: [GC (Allocation Failure) 2018-02-03T15:28:17.555+0000: 16.746: [SoftReference, 0 refs, 0.0000253 secs]2018-02-03T15:28:17.555+0000: 16.746: [WeakReference, 158 refs, 0.0000118 secs]2018-02-03T15:28:17.555+0000: 16.746: [FinalReference, 132 refs, 0.0008342 secs]2018-02-03T15:28:17.556+0000: 16.747: [PhantomReference, 0 refs, 18 refs, 0.0000073 secs]2018-02-03T15:28:17.556+0000: 16.747: [JNI Weak Reference, 0.0000054 secs][PSYoungGen: 42179K->3811K(46080K)] 96734K->60118K(109056K), 0.0094421 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]

As well as a number of Java stack traces. After collecting a support log bundle to see if this is a known issue I bounced the vapi service:

$ service-control --stop vmware-vapi-endpoint

Perform stop operation. vmon_profile=None, svc_names=['vmware-vapi-endpoint'], include_coreossvcs=False, include_leafossvcs=False
Successfully stopped service vapi-endpoint

$ service-control --start vmware-vapi-endpoint

Perform start operation. vmon_profile=None, svc_names=['vmware-vapi-endpoint'], include_coreossvcs=False, include_leafossvcs=False
2018-02-03T15:33:42.253Z   Service vapi-endpoint state STOPPED
Successfully started service vapi-endpoint

$ service-control --status vmware-vapi-endpoint

Running:
 vmware-vapi-endpoint

Once the service restarted I was able to re-run my plan and apply my changes. Now back to our regular programming.

This article was posted by Matty on 2018-02-03 11:03:32 -0500 -0500