Recently, was working on a interesting problem with vRA 7.3 where user's request get's into IN PROGRESS state after a successful approval

UI does not show any exceptions and you have to dig through the logs to understand what's going on

One common point was all of these requests were submitted more than a week ago. Any request's submitted less than a week were successful as expected

Let's take an example

Request ID: 685 Submitted: 1/30/18 9:26 AM THAI ( 2:26 AM UTC ) Approved: 2/6/18 11:52 AM THAI ( 4:52 AM UTC)

RESULT: stuck at IN PROGRESS

1. Request submitted

catalina.out.1:2018-01-30 02:26:01,631 vcac: [component="cafe:composition-service" priority="INFO" thread="tomcat-http--46" tenant="scb" context="7fo7jfi1" parent="lDW4Osr4" token="sedoWsTv"] com.vmware.vcac.composition.service.impl.RequestServiceImpl.validate:889 - Received request for requestedObjectId scb!::!RHEL7forTestPending, catalogRequestId a09a9b4a-32da-4bb4-b754-a95f93f8dc38, requestNumber 685, resourceId null

2. RequestedItemApprovalId for this request was 063c130c-e105-43e9-b0a8-b413ca5e7e69

catalina.out.1:2018-01-30 02:26:03,710 vcac: [component="cafe:approvals" priority="INFO" thread="queue-pool-executer-2" tenant="scb" context="7fo7jfi1" parent="we7d9TMH" token="1kGg7dFR"] com.vmware.vcac.core.approvals.service.workitems.ApprovalRequestPublisherImpl.logSuccess:172 - ApprovalRequest [ApprovalRequestId="844a385a-8e07-42eb-90c7-0f805811b3c1" Name="Level#1: L1" Policy="AP Request VM"] : {Level#1: L1} - Created work item for approvers in Approval Request catalina.out.1:2018-01-30 02:26:03,717 vcac: [component="cafe:approvals" priority="INFO" thread="queue-pool-executer-2" tenant="scb" context="7fo7jfi1" parent="we7d9TMH" token="1kGg7dFR"] com.vmware.vcac.core.approvals.service.impl.ApprovalProcessor.processRequestedItemApprovalInternal:159 - RequestedItemApproval [RequestedItemApprovalId="063c130c-e105-43e9-b0a8-b413ca5e7e69" RequestedItemName="" RequestedFor=""] : Finished creating work item and/or notifying requesting service for Requested Item Approval

3. Approval is now complete after 7 days

2018-02-06 04:52:27,751 vcac: [component="cafe:approvals" priority="INFO" thread="queue-pool-executer-1" tenant="scb" context="G629x9nq" parent="69CYz90w" token="YPKbdSDF"] com.vmware.vcac.core.approvals.service.impl.DataUpdateCallbackServiceImpl.update:46 - RequestedItemApproval [RequestedItemApprovalId="063c130c-e105-43e9-b0a8-b413ca5e7e69" RequestedItemName="" RequestedFor=""] : Sending update for approval.. 2018-02-06 04:52:29,752 vcac: [component="cafe:catalog" priority="INFO" thread="tomcat-http--35" tenant="scb" context="G629x9nq" parent="LSHr7E7h" token="fh5G8UZV"]

com.vmware.vcac.catalog.service.impl.RequestServiceImpl.requestApprovalEvent:694 - Request [RequestId ="a09a9b4a-32da-4bb4-b754-a95f93f8dc38" TenantName="" SubtenantName=""] : Received approval event {APPROVAL_COMPLETION} for Request with ApprovalId {42efc619-a4a6-43da-88e0-e17269453399}.

4. Final phases of approval

2018-02-06 04:52:30,004 vcac: [component="cafe:event-broker" priority="INFO" thread="ebs-queue-pool-executer-3" tenant="" context="" parent="" token=""] com.vmware.vcac.eventlog.auditing.saveEvent:90 - Approval [Id="42efc619-a4a6-43da-88e0-e17269453399"] : Notified the requesting service {d87206ce-d0e4-4f2b-85a5-601cd0323ed1} about the completion of Approval with final state {APPROVED}

5. Request now submitted to provider

2018-02-06 04:52:31,184 vcac: [component="cafe:catalog" priority="INFO" thread="queue-pool-executer-1" tenant="scb" context="G629x9nq" parent="fh5G8UZV" token="DuQcAKO8"] com.vmware.vcac.catalog.schema.ExternalRequestDataProvider.getData:74 - CatalogItemRequest [RequestId="a09a9b4a-32da-4bb4-b754-a95f93f8dc38" CatalogItemId="4eea22d6-899a-48f2-8b3b-4365184be78a" CatalogItemName="RHEL7 (for Test Pending)" ServiceName="Standard Blueprint" TenantName="SCB" SubtenantName="Test-BG"] : Retrieving field values from provider for component {} of request

6. Exception is seen here

2018-02-06 04:52:31,175 vcac: [component="cafe:catalog" priority="ERROR" thread="queue-pool-executer-4" tenant="scb" context="G629x9nq" parent="fh5G8UZV" token="6akaGyTr"] com.vmware.vcac.catalog.events.RequestLifecycleEventListener.requestApproved:102 - Request [RequestId ="a09a9b4a-32da-4bb4-b754-a95f93f8dc38" TenantName="" SubtenantName=""] : Error processing request approved event for request java.lang.IllegalArgumentException: Delegated token must be instance of class com.vmware.vcac.authentication.http.spring.oauth2.OAuth2Token: null at org.springframework.util.Assert.instanceCheckFailed(Assert.java:389) ~[spring-core-4.3.7.RELEASE.jar:4.3.7.RELEASE] at org.springframework.util.Assert.isInstanceOf(Assert.java:327) ~[spring-core-4.3.7.RELEASE.jar:4.3.7.RELEASE] at com.vmware.vcac.authentication.sts.OAuth2TokenService.propagatingAuthenticationWithDelegationFor(OAuth2TokenService.java:108) ~[platform-security-sso-client-7.3.0-SNAPSHOT.jar:?] at com.vmware.vcac.core.componentregistry.rest.client.EndPointAuthenticationManager.propagatingAuthenticationWithDelegationFor(EndPointAuthenticationManager.java:185) ~[component-registry-client-rest-service-7.3.0-SNAPSHOT.jar:?] at com.vmware.vcac.core.componentregistry.rest.client.SolutionRestClientManager.getAuthentication(SolutionRestClientManager.java:302) ~[component-registry-client-rest-service-7.3.0-SNAPSHOT.jar:?]

Let me explain the reason for failure

After approval service notifies catalog of approval completion, the catalog service tries to submit the request to the provider. This submission is eventually failing while getting client token.

Error Message: [Delegated token must be instance of class com.vmware.vcac.authentication.http.spring.oauth2.OAuth2Token: null].

Token used in for the request is deleted after a certain period which is 7 days. Once deleted from database it cannot be retrieved. Hence the NULL value is passed and causes request to stuck at "IN PROGRESS" state

Token are removed after 7 days or when the operation needing them is completed.

This is not a bug but it's a product behavior.

If you delay approvals for a long time, then you are bound to hit this issue

If any administrator wants to extend the validity of the token used to invoke a request after approval s/he can set

persistentTokenManager.staleTokenAgeDays=14

in /etc/vcac/vcac.properties

This change to token age has to be done on all the vRA appliances

Keep these points in mind

1. The vcac-server service needs to get restarted in order for the setting to be applied 2. Any requests created before the restart will still have the default validity (7 days)

You may use this KB https://kb.vmware.com/s/article/2114385 to remove any IN PROGRESS or PENDING APPROVAL requests. If you would like to automate them then you got to build custom workflow.