Virtual Agent --- Teams Integration Messages are Sometimes not Sent and Requires the User to Try Sending Again Multiple Times, node log error: Encountered issue while processing the message !


Description

Virtual Agent --- Teams Integration Messages are sometimes not sent and requires the user to try sending again multiple times.

When the issue happens the following is seen in the node logs (notice: Encountered issue while processing the message !) :

09/03/20 16:38:31 (675) SYSTEM #2122198 /api/now/v1/proxy/cs/adapter/va/teams/activity Parameters -------------------------
api=api
09/03/20 16:38:31 (675) SYSTEM *** Start #2122198 /api/now/v1/proxy/cs/adapter/va/teams/activity, user: guest
09/03/20 16:38:31 (675) SYSTEM #2122198 [REST API] RESTAPIProcessor : Processing REST Request /api/now/v1/proxy/cs/adapter/va/teams/activity
09/03/20 16:38:31 (675) SYSTEM #2122198 [REST API] RESTAPIProcessor : Request Method:POST
09/03/20 16:38:31 (675) SYSTEM #2122198 [REST API] RESTAPIProcessor : Request Header: host:test.service-now.com
09/03/20 16:38:31 (675) SYSTEM #2122198 [REST API] RESTAPIProcessor : Request Header: content-length:1162
09/03/20 16:38:31 (675) SYSTEM #2122198 [REST API] RESTAPIProcessor : Request Header: contextid:tcid=1041847841234117876, server=AB2PEPF000043CC
09/03/20 16:38:31 (675) SYSTEM #2122198 [REST API] RESTAPIProcessor : Request Header: user-agent:Microsoft-SkypeBotApi (Microsoft-BotFramework/3.0)
09/03/20 16:38:31 (675) SYSTEM #2122198 [REST API] RESTAPIProcessor : Request Header: ms-cv:abcd.1
09/03/20 16:38:31 (675) SYSTEM #2122198 [REST API] RESTAPIProcessor : Request Header: content-type:application/json; charset=utf-8
09/03/20 16:38:31 (675) SYSTEM #2122198 [REST API] RESTAPIProcessor : Request Header: x-forwarded-proto:https
09/03/20 16:38:31 (675) SYSTEM #2122198 [REST API] RESTAPIProcessor : Request Header: x-forwarded-host:test.service-now.com
09/03/20 16:38:31 (675) SYSTEM #2122198 [REST API] RESTAPIProcessor : Request Header: x-forwarded-for:10.24.5.2
09/03/20 16:38:31 (675) SYSTEM #2122198 [REST API] RESTAPIProcessor : Pre-Service processing duration duration_micro_secs=8079
09/03/20 16:38:31 (675) SYSTEM #2122198 [REST API] ServiceHandler : Service class: VAProxyTeamsWebhookResource
09/03/20 16:38:31 (675) SYSTEM #2122198 [REST API] ServiceHandler : Resolving service method reference: webhook
09/03/20 16:38:31 (675) SYSTEM #2122198 [REST API] ServiceHandler : Invoking service method
09/03/20 16:38:31 (675) SYSTEM #2122198 [REST API] RequestDeserializer : Incoming Request Body:{"timestamp":"2020-09-03T22:38:31.189Z","localTimestamp":"2020-09-03T16:38:31.189-06:00","entities":[{"locale":"en-US","platform":"Windows","country":"US","type":"clientInfo"}],"id":"f:1041847847943117876","from":{"name":"Person Person","aadObjectId":"e823da88-a17b-4ec0-b2a6-0fffb86e0103","id":"29:1_o82xtUeM83A6YuKrAoDS3HMtUpsHDURegICa4lJgXGjex24tF4CnhJHT_M9cfiKVmrj8_OcidJGDDd3sKdsBA"},"locale":"en-US","originServiceUrl":"https:\/\/smba.trafficmanager.net\/amer\/","text":"incident","channelData":{"tenant":{"id":"f863af7a-e568-42bc-8847-9367921cb2ad"},"legacy":{"replyToId":"1:1apci2GOamHZ-mlyrVL6qd9er7-pGU5HtWFAWsNITdwU"},"source":{"name":"message"}},"value":{"property":"incident"},"replyToId":"1599112341024","recipient":{"name":"Now Virtual Agent","id":"28:49471a10-fdbc-4ffb-b0b8-9441234f985d9"},"conversation":{"tenantId":"f863af7a-c123-42bc-8847-9367921cb2ad","id":"a:1E3rpCON68nrLbjvILlw1rOx3Eha8vYXAhvhBddZQtjPXbLqkMzjcGfH4t5R6agfeqbxZyE9Ynxr2qn-IxJpSjFJdXw0VZeFw3YDLajUpDRXgYoh8XC91Z_k8rSKGqHVb","conversationType":"personal"},"channelId":"msteams","serviceUrl":"https:\/\/teamsproxy.service-now.com\/\/teams\/va\/outbound\/","type":"message"}
09/03/20 16:38:31 (686) SYSTEM [Context] [MsAdapterMgr] Encountered issue while processing the message !
09/03/20 16:38:31 (686) SYSTEM #2122198 [REST API] ServiceHandler : End of Service Invocation VAProxyTeamsWebhookResource
09/03/20 16:38:31 (686) SYSTEM #2122198 [REST API] ServiceHandler : Service Invocation Duration duration_micro_secs=10994
09/03/20 16:38:31 (686) SYSTEM #2122198 [REST API] ServiceResultHandler : Serializing Response
09/03/20 16:38:31 (686) SYSTEM #2122198 [REST API] ServiceResultHandler : End of Response Serialization
09/03/20 16:38:31 (686) SYSTEM #2122198 [REST API] ServiceResultHandler : Response Serialization Duration duration_micro_secs=43
09/03/20 16:38:31 (686) SYSTEM #2122198 [REST API] RESTAPIProcessor : Service handling duration duration_micro_secs=11103
09/03/20 16:38:31 (686) SYSTEM #2122198 [REST API] RESTAPIProcessor : End of Request Processing
09/03/20 16:38:31 (686) SYSTEM #2122198 [REST API] RESTAPIProcessor : REST Request Processing time total_time_to_now_micro_secs=19372
09/03/20 16:38:31 (688) SYSTEM *** End #2122198 /api/now/v1/proxy/cs/adapter/va/teams/activity, user: guest, total time: 0:00:00.020, processing time: 0:00:00.020, SQL time: 0:00:00.004 (count: 18), source: 10.242.65.20 , type:rest, method:POST, api_name:now/proxy, resource:now/v1/proxy/cs/adapter/va/teams/activity, version:v1, user_id:5136503cc611227c0183e96598c4f706, response_status:200

Release or Environment

Applies to any environment.

Cause

The setting for system property va.adapter.max.processing.time needs adjustment. 

Resolution

Set the system property va.adapter.max.processing.time from this, Value is in milliseconds:

Name = va.adapter.max.processing.time
Type = integer
Value = 60000

To this:

Name = va.adapter.max.processing.time
Type = integer
Value = 100

With the original setting of 60000ms, this made messages look like they were requests that should not be processed right away, causing users to resend on failure.