Performance of VAPI plugin

[randomname]

I've noticed that running (some) code through the VAPI plugin is extremely slow. For example, a single call to the list() method of a com_vmware_cis_tagging_category object takes nearly 10 seconds. This time seems to increase exponentially when I'm running many calls in parallel. When running a few as 10 parallel workflows, the same list call can take in excess of 10 minutes for the first few workflows, which slowly reduces as running workflows complete.

Comparatively, doing it in PowerShell with a Cis server connection by getting the com.vmware.cis.tagging.category service and calling its list() method returns results in a few milliseconds.

In this environment, there are only 10 categories and a few hundred tags.

In vRO with VAPI plugin:

var vapiEndpoint = VAPIManager.getAllEndpoints()[0];

var vapiClient = vapiEndpoint.client();

var cisTagCat = new com_vmware_cis_tagging_category(vapiClient);

System.log("get cats start");

var tagCats = cisTagCat.list();

System.log("get cats end");

[2018-11-21 08:05:18.754] [I] get cats start

[2018-11-21 08:05:28.144] [I] get cats end

In PowerShell:

$cisObjTagCatSvc = Get-CisService -Name "com.vmware.cis.tagging.category" -Server $viObjCisServer

(Measure-Command -Expression {$cisObjTagCats = $cisObjTagCatSvc.list()}).TotalSeconds

0.0340482

Even if I measure from the initial connections, it's still much faster in PowerShell than the VAPI plugin.

(Measure-Command -Expression {$viObjCisServer = Connect-CisServer -Server "<myVc>" -Credential $cred

$cisObjTagCatSvc = Get-CisService -Name "com.vmware.cis.tagging.category" -Server $viObjCisServer

$cisObjTagCats = $cisObjTagCatSvc.list()}).TotalSeconds

2.6297053

And in vRO as straight REST call in a script item:

var uri = "https://<myVc>/rest/com/vmware/cis/tagging/category";

var restHost = RESTHostManager.createHost("DynamicRequest");

var transientHost = RESTHostManager.createTransientHostFrom(restHost);

transientHost.url = uri;

var request = transientHost.createRequest("GET",uri,"");

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

System.log("request start");

var response = request.execute();

System.log("request end");

[2018-11-21 08:12:58.891] [I] request start

[2018-11-21 08:12:59.000] [I] request end

Any ideas what is going on here? Is this expected for the VAPI plugin? Are improvements in the pipeline?

vRO is 7.4, VAPI plugin is whatever version is the latest posted in this forum's "Documents" page as of today.

[iiliev]

Definitely not expected to be that slow. I'll try to perform a similar benchmark in my environment to compare the results.

One question - what kind of permissions does the account you use in vAPI plug-in have on vCenter side; eg. is it an administrator or a regular user?

Also, if you try to call the same vAPI method the second time in the same scriptable task (immediately after the first method call), does the second call take a comparable amount of time as the first one, or is much faster?

[iiliev]

Result from my 7.4 with the same vAPI plug-in build:

[2018-11-21 23:55:26.053] [I] get cats start

[2018-11-21 23:55:26.513] [I] get cats end

10 tag categories with 30 tags in each category (total 300 tags)

460 milliseconds

[randomname]

Thanks for taking a look.

The account being used is an administrator of both vCenter and Orchestrator.

Subsequent methods called on objects from an existing VAPI client object do not seem to exhibit the delay. If I create a new VAPI client object, then calling list() from a tagging category object created from that new client object does exhibit the delay. All executions of getting the endpoints, creating the client object, and creating the tagging category object all complete nearly instantly. It is only when I'm calling methods from objects created from the client that the delay is observed.

System.log("get endpoint start");

var vapiEndpoint = VAPIManager.getAllEndpoints()[0];

System.log("get endpoint end");

System.log("create client start 1");

var vapiClient = vapiEndpoint.client();

System.log("create client end 1");

System.log("create tag cat cis obj start 1");

var cisTagCat = new com_vmware_cis_tagging_category(vapiClient);

System.log("create tag cat cis obj end 1");

System.log("get cats start 1");

var tagCats = cisTagCat.list();

System.log("get cats end 1");

System.log("get cats start 2");

var tagCats = cisTagCat.list();

System.log("get cats end 2");

System.log("create client start 2");

var vapiClient = vapiEndpoint.client();

System.log("create client end 2");

System.log("create tag cat cis obj start 2");

var cisTagCat = new com_vmware_cis_tagging_category(vapiClient);

System.log("create tag cat cis obj end 2");

System.log("get cats start 3");

var tagCats = cisTagCat.list();

System.log("get cats end 3");

vapiClient.close()

[2018-11-23 08:35:43.581] [I] get endpoint start

[2018-11-23 08:35:43.586] [I] get endpoint end

[2018-11-23 08:35:43.587] [I] create client start 1

[2018-11-23 08:35:43.588] [I] create client end 1

[2018-11-23 08:35:43.590] [I] create tag cat cis obj start 1

[2018-11-23 08:35:43.591] [I] create tag cat cis obj end 1

[2018-11-23 08:35:43.593] [I] get cats start 1

[2018-11-23 08:35:52.598] [I] get cats end 1

[2018-11-23 08:35:52.604] [I] get cats start 2

[2018-11-23 08:35:52.638] [I] get cats end 2

[2018-11-23 08:35:52.640] [I] create client start 2

[2018-11-23 08:35:52.641] [I] create client end 2

[2018-11-23 08:35:52.643] [I] create tag cat cis obj start 2

[2018-11-23 08:35:52.644] [I] create tag cat cis obj end 2

[2018-11-23 08:35:52.645] [I] get cats start 3

[2018-11-23 08:36:01.721] [I] get cats end 3

I've gone through the VAPI logs on vCenter and the logs on Orchestrator. I can see entries for some of the operations (getting a token and creating a session in VAPI log), but there doesn't seem to be any explicit logging of the actual method calls. None of the entries that are logged look abnormal.

I don't see this kind of issue going anywhere with a support incident, so I guess I'm left rewriting everything I've been doing with the VAPI plugin with raw REST code instead. At least all my tagging code, which is high volume and high frequency due to the quantity of objects being tagged.

[iiliev]

If you are willing to test it further, I can make and send you a new build of vAPI plug-in, using a newer version of vAPI PDK libs, to check if this will make a difference. And possibly some additional logging in plug-in's Java code to try to figure out which part is taking that much time - the actual vAPI method call, vAPI session creation, vAPI method permissions' checking, etc.

[randomname · Accepted solution]

I figured it out. While poking around the control center, I noticed that Trusted Certificates conspicuously took about 10 seconds to open. This is about the same amount of time as the VAPI method call took. Thinking that perhaps the method was trying to create a secure connection to vCenter, and perhaps was referencing the same certificate store to validate that connection, and perhaps was then suffering the same performance hit trying to enumerate the store, I created a workflow to clean up all the certificates I didn't immediately need. Those being the hundreds of certificates of devices left over from workflows which add them during execution because they're all self signed and needed for the runtime connection. Now the VAPI method completes almost immediately.

So I'll just have to update all my actions which add certificates to remove each respective certificate after completion. Not a bad thing to do anyway for good housekeeping. Just never thought of it as necessary before.