VM provisioning in vCenter using 3rd party applications might fail with an error "500 Internal Server Error"
search cancel

VM provisioning in vCenter using 3rd party applications might fail with an error "500 Internal Server Error"

book

Article ID: 377421

calendar_today

Updated On:

Products

VMware vCenter Server 8.0 VMware vCenter Server 7.0

Issue/Introduction

  • You are using a third party application like Terraform to automate VM deploying in a vSphere environment
  • Occasionally the deployment fails with "500 Internal Server Error", like in the example screenshot from Terraform below:

  • When reviewing the vpxd-svcs logs in /var/log/vmware/vpxd-svcs, errors like in the following example can be found:

XXXX-XX-XXT11:26:26.096+08:00 [tomcat-exec-272 [] INFO  com.vmware.vim.sso.client.impl.SecurityTokenServiceImpl  opId=] Successfully acquired token for user: {Name: USERNAME, Domain: VSPHERE.LOCAL}
XXXX-XX-XXT11:26:26.096+08:00 [tomcat-exec-272 [] INFO  com.vmware.cis.authorization.impl.AuthorizationManagerImpl  opId=] Session count for user [after add]: VSPHERE.LOCAL\USERNAME is 200
XXXX-XX-XXT11:26:26.107+08:00 [tomcat-exec-250 [] INFO  com.vmware.identity.token.impl.SamlTokenImpl  opId=] SAML token for SubjectNameId [[email protected], format=http://schemas.xmlsoap.org/claims/UPN] successfully parsed from Element
XXXX-XX-XXT11:26:26.107+08:00 [tomcat-exec-250 [] WARN  com.vmware.cis.authorization.impl.AuthorizationManagerImpl  opId=] Session limit reached for user: VSPHERE.LOCAL\USERNAME with 200 sessions.
XXXX-XX-XXT11:26:26.107+08:00 [tomcat-exec-250 [] ERROR com.vmware.vim.vcauthenticate.servlets.AuthenticationHelper  opId=] Authentication error: com.vmware.vim.vcauthenticate.exception.VimAuthenticateException: com.vmware.cis.core.exception.AuthorizationException: Too many sessions for user: VSPHERE.LOCAL\USERNAME with 200 sessions.
XXXX-XX-XXT11:26:26.107+08:00 [tomcat-exec-250 [] WARN  com.vmware.vapi.internal.bindings.ApiMethodSkeleton  opId=] Implementation method reported unexpected exception: java.lang.RuntimeException
java.lang.RuntimeException: Rejecting login on a session where login failed
        at com.vmware.cis.services.common.vapi.sessions.impl.VlsiBackedSessionManager.loginInt(VlsiBackedSessionManager.java:164) [service-common.jar:?]

Environment

VMware vCenter Server 7.0.x

VMware vCenter Server 8.0.x

Cause

Endpoint Limits for Concurrent REST Requests.

Resolution

The issue occurs when the available session limit for the REST API has been exhausted

The maximum number of sessions that can be open for the REST API is limited to 200 per user, as soon as there are 200 concurrently open sessions for the API by this user, any attempt to open a further session will be denied, leading to the error above.

  • To identify if the automation software is responsible for the session exhaustion, start with reviewing the envoy-access logs of the envoy reverse proxy in /var/log/vmware/envoy/:

$ grep "/sdk HTTP/2 500 via_upstream.*<SOURCEIP>" envoy-access-9057.log
XXXX-XX-XXTXX:XX:XX.XXXX info envoy[140390803613504] [Originator@6876 sub=Default] XXXX-XX-XXT03:26:22.718Z POST /sdk HTTP/2 500 via_upstream - 1135 703 3 3 0 <SOURCEIP>:41770 XX.XX.XX.XX:443 127.0.0.1:59512 127.0.0.1:8085
XXXX-XX-XXT03:26:23.XXXX info envoy[140390803613504] [Originator@6876 sub=Default] XXXX-XX-XXT03:26:23.016Z POST /sdk HTTP/2 500 via_upstream - 1135 703 4 4 0 <SOURCEIP>:41770 XX.XX.XX.XX:443 127.0.0.1:59512 127.0.0.1:8085
XXXX-XX-XXT03:XX:XX.XXXX info envoy[140390803613504] [Originator@6876 sub=Default] XXXX-XX-XXT03:26:23.954Z POST /sdk HTTP/2 500 via_upstream - 1135 703 4 4 0 <SOURCEIP>:41852 XX.XX.XX.XX:443 127.0.0.1:49632 127.0.0.1:8085

  • Now review the VAPI endpoint access log in /var/log/vmware/vapi/endpoint:

$ grep 'HTTP/1.1" 500' endpoint-access.log
XXXX-XX-XXT11:26:26.109+08:00 | vAPI-I/O dispatcher-1   | XX.XX.XX.XX - - [12/Sep/2024:03:26:25 +0000] "GET /rest/com/vmware/cis/tagging/category HTTP/1.1" 500 351 "-" "terraform-provider-vsphere_v2.8.1_x5 govmomi/0.37.1 (go1.22.2;linux;amd64)" 281
XXXX-XX-XXT11:26:26.116+08:00 | vAPI-I/O dispatcher-0   | XX.XX.XX.XX - - [12/Sep/2024:03:26:25 +0000] "GET /rest/com/vmware/cis/tagging/category HTTP/1.1" 500 351 "-" "terraform-provider-vsphere_v2.8.1_x5 govmomi/0.37.1 (go1.22.2;linux;amd64)" 280
XXXX-XX-XXT11:31:28.777+08:00 | vAPI-I/O dispatcher-0   | XX.XX.XX.XX - - [12/Sep/2024:03:31:28 +0000] "POST /rest/com/vmware/cis/tagging/tag-association?~action=list-attached-tags HTTP/1.1" 500 351 "-" "terraform-provider-vsphere_v2.8.1_x5 govmomi/0.37.1 (go1.22.2;linux;amd64)" 167
XXXX-XX-XXT11:31:31.161+08:00 | vAPI-I/O dispatcher-0   | XX.XX.XX.XX - - [12/Sep/2024:03:31:31 +0000] "POST /rest/com/vmware/cis/tagging/tag-association?~action=list-attached-tags HTTP/1.1" 500 351 "-" "terraform-provider-vsphere_v2.8.1_x5 govmomi/0.37.1 (go1.22.2;linux;amd64)" 149

  • As we can see above, error 500 returned for the request from source for tagging category. Here we need to check the vpxd-svcs log for the same time stamp.

XXXX-XX-XXT11:26:26.096+08:00 [tomcat-exec-272 [] INFO  com.vmware.vim.sso.client.impl.SecurityTokenServiceImpl  opId=] Successfully acquired token for user: {Name: USERNAME, Domain: VSPHERE.LOCAL}
XXXX-XX-XXT11:26:26.096+08:00 [tomcat-exec-272 [] INFO  com.vmware.cis.authorization.impl.AuthorizationManagerImpl  opId=] Session count for user [after add]: VSPHERE.LOCAL\<USERNAME> is 200
XXXX-XX-XXT11:26:26.107+08:00 [tomcat-exec-250 [] INFO  com.vmware.identity.token.impl.SamlTokenImpl  opId=] SAML token for SubjectNameId [[email protected], format=http://schemas.xmlsoap.org/claims/UPN] successfully parsed from Element
XXXX-XX-XXT11:26:26.107+08:00 [tomcat-exec-250 [] WARN  com.vmware.cis.authorization.impl.AuthorizationManagerImpl  opId=] Session limit reached for user: VSPHERE.LOCAL\<USERNAME> with 200 sessions.
XXXX-XX-XXT11:26:26.107+08:00 [tomcat-exec-250 [] ERROR com.vmware.vim.vcauthenticate.servlets.AuthenticationHelper  opId=] Authentication error: com.vmware.vim.vcauthenticate.exception.VimAuthenticateException: com.vmware.cis.core.exception.AuthorizationException: Too many sessions for user: VSPHERE.LOCAL\USERNAME with 200 sessions.
XXXX-XX-XXT11:26:26.107+08:00 [tomcat-exec-250 [] WARN  com.vmware.vapi.internal.bindings.ApiMethodSkeleton  opId=] Implementation method reported unexpected exception: java.lang.RuntimeException
java.lang.RuntimeException: Rejecting login on a session where login failed
        at com.vmware.cis.services.common.vapi.sessions.impl.VlsiBackedSessionManager.loginInt(VlsiBackedSessionManager.java:164) [service-common.jar:?]

In this example, the user VSPHERE.LOCAL\<USERNAME> holds 200 open REST API sessions at the same time, thus exhausting its session limit. .

To resolve this, please modify the automation script to ensure it does not the maximum limit of 200 concurrent API sessions number this 200-session limit for a single user. This can be achieved by implementing proper session management techniques, such as:

  • Reusing existing sessions rather than opening new ones for every request.
  • Closing or terminating sessions once they are no longer needed.
  • Implementing rate-limiting or throttling mechanisms to control session creation.

Additional Information