rkrichevskiy
Enthusiast
Enthusiast

REST client errors with vAPI endpoint

Just wanted to run this by the community to see if anyone observed this in their environments (vRO 7.2/vCenter 6.5)

Getting this error intermittently and not able to simulate on demand:

Status code 500

{"type":"com.vmware.vapi.std.errors.internal_server_error","value":{"messages":[{"args":["Rejecting login on a session where login failed"],"default_message":"Provider method implementation threw unexpected exception: Rejecting login on a session where login failed","id":"vapi.bindings.method.impl.unexpected"}]}} (Dynamic Script Module name : promiseTagCategory#74)

Line 74 would be this:

function getTagCategories(restHost,sessionID) {

    var request = restHost.createRequest("GET", "/com/vmware/cis/tagging/category");

    request.setHeader("vmware-api-session-id",sessionID);

    var response = request.execute();

    if (response.statusCode != 200) throw "Status code " + response.statusCode + "\n" + response.contentAsString;

    // Returning an array of tag category ids

    return (JSON.parse(response.contentAsString)).value;

}

Sounds like server side is the culprit but I am not certain what to look for on vCenter to debug further.

0 Kudos
7 Replies
iiliev
VMware Employee
VMware Employee

First, check vAPI endpoint logs; I think they are under /storage/log/vmware/vapi/endpoint

Is it possible that you execute large number of requests against vAPI endpoint for relatively short period of time? vAPI endpoint does some rate limiting, although I'm not sure if it will fail with this exact error if the limit is reached.

0 Kudos
rkrichevskiy
Enthusiast
Enthusiast

We had cases reported where a very small number of requests triggered either this condition or plain Read timed out. We are handling them with retries for the most part but at this point the failure rate seems to be increasing, so I wanted to see if we can get it resolved. What's odd is that I can't simulate it on demand with something like async workflow call with about 50 requests at a time.

Thanks for the log pointer. We'll investigate it further.

0 Kudos
rkrichevskiy
Enthusiast
Enthusiast

on server side the endpoint.log has warnings:

WARN  | vAPI-I/O dispatcher-1     | SessionApiSecurityUtil         | Failed to create child session with session manager com.vmware.cis.tagging.sessions.session_manager for session ID (internal id , token ...).

com.vmware.vapi.std.errors.internal_server_error => {data=<unset>, messages=[com.vmware.vapi.std.localizable_message => {args=[Rejecting login on a session where login failed], default_message=Provider method implementation threw unexpected exception: Rejecting login on a session where login failed, id=vapi.bindings.method.impl.unexpected}]}

Does that "Failed to create child session" to create session mean anything to you?

thanks,

0 Kudos
iiliev
VMware Employee
VMware Employee

I think this error is thrown by vAPI endpoint when a login by SAML token fails, but I'm not sure how it can be troubleshooted further because I'm not familiar with vAPI REST internals. Perhaps this error could happen if the sessionID refers to invalid/expired session, or maybe there is some pattern that need to be followed when vAPI REST is called to ensure that sessions are properly renewed/cleaned up.

0 Kudos
rkrichevskiy
Enthusiast
Enthusiast

What I noticed is that the session is destroyed after an hour according to the endpoint log. So there could be something to the idea that we are accumulating sessions. deleteCisSession (similar to this code​) is commented out due to error code 401's we were receiving during implementation. My next step will be enabling deleteCisSession and monitor for further errors.

By any chance do you know where vCenter has endpoint properties configured? I found this ref doc but not finding any properties with the same names anywhere.

0 Kudos
iiliev
VMware Employee
VMware Employee

Check the files under /etc/vmware-vapi/

0 Kudos
MehdiBennadja
Contributor
Contributor

Hello,

I've got the same issue regarding applying tags to VMs, around 100 works perfectly then after the message "Rejecting login on a session where login failed" comes.

I've look in /storage/log/vmware/vapi/endpoint/endpoint.log and I've see many sessions destroy cause of unused or idle.

INFO  | session-monitor1      | MasterSessionMonitor       | Session Administrator@VSPHERE.LOCAL (internal id 338789b9-e462-4a7c-8a81-3c4c75559f26, token cfb0d...) has been idle for 3,600,616 milliseconds.

The "var client = endpoint.client();" create the session but the session is never closed.

endpoint.client(); return a VAPIClient so we can use client.close();

So at the end of my workflow I've add this line and now the workflow works and I can attach tag to more than 100 VMs.

if (endpoint == null) {

  throw "'endpoint' parameter should not be null";

}

var client = endpoint.client();

var tagsvc = new com_vmware_cis_tagging_tag__association(client); 

var dynid = new com_vmware_vapi_std_dynamic__ID(); 

dynid.id = vmid; 

dynid.type = "VirtualMachine"; 

tagsvc.attach_multiple_tags_to_object(dynid, tagid);

client.close();

This works but now endpoint.log is just poluated as at every times I attach tag I create a session than close.

2018-04-19T17:21:11.257+02:00 | INFO  | sso3                  | BaseSessionImpl            | Created session is valid until 4/20/18 5:21 PM
2018-04-19T17:21:11.257+02:00 | INFO  | sso3                  | MasterSessionManagerImpl   | Created session Administrator@VSPHERE.LOCAL (internal id c399033a-3cc0-4234-8684-cf9c8a318017, token 24ebd...)
2018-04-19T17:21:11.273+02:00 | INFO  | vAPI-I/O dispatcher-0 | SessionApiSecurityUtil     | Created child session with session manager com.vmware.cis.tagging.sessions.session_manager for session Administrator@VSPHERE.LOCAL (internal id c399033a-3cc0-4234-8684-cf9c8a318017, token 24ebd...).
2018-04-19T17:21:11.312+02:00 | INFO  | jetty-default-15952   | PublicSessionManager       | Deleting session Administrator@VSPHERE.LOCAL (internal id c399033a-3cc0-4234-8684-cf9c8a318017, token 24ebd...)
2018-04-19T17:21:11.312+02:00 | INFO  | jetty-default-15952   | MasterSessionManagerImpl   | Logggin out session. Setting session Administrator@VSPHERE.LOCAL (internal id c399033a-3cc0-4234-8684-cf9c8a318017, token 24ebd...) to INACTIVE.
2018-04-19T17:21:11.533+02:00 | INFO  | session-monitor1      | MasterSessionMonitor       | Session Administrator@VSPHERE.LOCAL (internal id ead8ea2c-378c-4922-a75b-92a5f97dd88f, token 3dfc9...) no more used. Start destroying it...
2018-04-19T17:21:11.533+02:00 | INFO  | session-monitor1      | MasterSessionMonitor       | Session Administrator@VSPHERE.LOCAL (internal id ead8ea2c-378c-4922-a75b-92a5f97dd88f, token 3dfc9...) completely destroyed.
2018-04-19T17:21:11.533+02:00 | INFO  | session-monitor1      | MasterSessionMonitor       | Session Administrator@VSPHERE.LOCAL (internal id c399033a-3cc0-4234-8684-cf9c8a318017, token 24ebd...) no more used. Start destroying it...
2018-04-19T17:21:11.533+02:00 | INFO  | session-monitor1      | MasterSessionMonitor       | Session Administrator@VSPHERE.LOCAL (internal id c399033a-3cc0-4234-8684-cf9c8a318017, token 24ebd...) completely destroyed.

Hopes it helps.

Regards,

0 Kudos