We have a significant delay in the 1st call after an application Tomcat restart. It seems the OD framework initilazes VPAppLogClient, gets global parameters from EPM, acquires license, etc. according to trace log. It can take 5-6 seconds. The 2nd and subsequent calls are fine.
- Is it normal behavior of OD framework, or there is a misconfiguration in the system?

Trace log (5 sec from start of session to first node of app) :

12/05/2022 14:52:43:035  INFO - 8A88ADDFC6408A4751C10C2E3468DBCE:/OD8_Test : SCESession bound to HttpSession 8A88ADDFC6408A4751C10C2E3468DBCE

12/05/2022 14:52:46:106  INFO - 8A88ADDFC6408A4751C10C2E3468DBCE:/OD8_Test : Browser Version 2.1.4, terminationURL enabled : true

12/05/2022 14:52:46:108 DEBUG - 8A88ADDFC6408A4751C10C2E3468DBCE:/OD8_Test : PlatformParams:getPlatformParams: __VPVarGlobalDate is 1652341821195

12/05/2022 14:52:46:108 DEBUG - 8A88ADDFC6408A4751C10C2E3468DBCE:/OD8_Test : PlatformParams:getPlatformParams:Timestamp is 05/12/22 9:50:21

12/05/2022 14:52:46:108 DEBUG - 8A88ADDFC6408A4751C10C2E3468DBCE:/OD8_Test : PlatformParams: get global parameters from VPMS...

12/05/2022 14:52:47:217 DEBUG - 8A88ADDFC6408A4751C10C2E3468DBCE:/OD8_Test : PlatformParams: AppRuntimeVarsResponse.getGlobalAppRuntimeVars returns status - success

12/05/2022 14:52:47:217 DEBUG - 8A88ADDFC6408A4751C10C2E3468DBCE:/OD8_Test : PlatformParams: get parameter|value - __VPLicenseServerURL|https://10.100.5.25:52233/WebLM/LicenseServer

12/05/2022 14:52:47:217 DEBUG - 8A88ADDFC6408A4751C10C2E3468DBCE:/OD8_Test : PlatformParams: get parameter|value - __VPConversationServer|

12/05/2022 14:52:47:217 DEBUG - 8A88ADDFC6408A4751C10C2E3468DBCE:/OD8_Test : PlatformParams: get parameter|value - __VPConversationServerTimeout|60

12/05/2022 14:52:47:218 DEBUG - 8A88ADDFC6408A4751C10C2E3468DBCE:/OD8_Test : PlatformParams: get parameter|value - __VPConversationServerType|Internal

12/05/2022 14:52:47:218 DEBUG - 8A88ADDFC6408A4751C10C2E3468DBCE:/OD8_Test : PlatformParams: get parameter|value - __VPConversationType|Internal

12/05/2022 14:52:47:218 DEBUG - 8A88ADDFC6408A4751C10C2E3468DBCE:/OD8_Test : PlatformParams: get parameter|value - __VPappintf|/axis2/services/VPAppIntfService

12/05/2022 14:52:47:218 DEBUG - 8A88ADDFC6408A4751C10C2E3468DBCE:/OD8_Test : PlatformParams: get parameter|value - __VPapplog|/axis2/services/VPAppLogService

12/05/2022 14:52:47:218 DEBUG - 8A88ADDFC6408A4751C10C2E3468DBCE:/OD8_Test : PlatformParams: get parameter|value - __VPappvars|/axis2/services/VPAppVarsService

12/05/2022 14:52:47:218 DEBUG - 8A88ADDFC6408A4751C10C2E3468DBCE:/OD8_Test : PlatformParams: get parameter|value - __VPepmguid|2c2f75c4-183f-4356-9847-f8aecafb6d05

12/05/2022 14:52:47:218 DEBUG - 8A88ADDFC6408A4751C10C2E3468DBCE:/OD8_Test : PlatformParams: get parameter|value - __VPzoneepm__0|10.100.5.20

12/05/2022 14:52:47:219 DEBUG - 8A88ADDFC6408A4751C10C2E3468DBCE:/OD8_Test : PlatformParams: get parameter|value - __VPzoneids|0

12/05/2022 14:52:47:219 DEBUG - 8A88ADDFC6408A4751C10C2E3468DBCE:/OD8_Test : PlatformParams: get parameter|value - __VPzonename__0|Default

12/05/2022 14:52:47:220  INFO - 8A88ADDFC6408A4751C10C2E3468DBCE:/OD8_Test : Using SCESession 8A88ADDFC6408A4751C10C2E3468DBCE:/OD8_Test servlet : Start

12/05/2022 14:52:47:250  INFO - 8A88ADDFC6408A4751C10C2E3468DBCE:/OD8_Test : ** Pushed Stack Frame [/OD8_Test]

12/05/2022 14:52:47:259  INFO - 8A88ADDFC6408A4751C10C2E3468DBCE:/OD8_Test : Storing :session___sessionid to complex: session:sessionid  as [iccsep8-2022132125234-15]

12/05/2022 14:52:47:271  INFO - 8A88ADDFC6408A4751C10C2E3468DBCE:/OD8_Test : runtime_platform : Experience Portal

12/05/2022 14:52:47:271  INFO - 8A88ADDFC6408A4751C10C2E3468DBCE:/OD8_Test : runtime_asr : Desktop Microsoft Speech SAPI

12/05/2022 14:52:47:421 DEBUG - 8A88ADDFC6408A4751C10C2E3468DBCE:/OD8_Test : Acquiring initial License

12/05/2022 14:52:47:422  INFO - 8A88ADDFC6408A4751C10C2E3468DBCE:/OD8_Test : Acquiring Avaya Platform runtime license

12/05/2022 14:52:47:422 DEBUG - 8A88ADDFC6408A4751C10C2E3468DBCE:/OD8_Test : PlatformParams:getPlatformParams: __VPVarGlobalDate is 1652341821195

12/05/2022 14:52:47:422 DEBUG - 8A88ADDFC6408A4751C10C2E3468DBCE:/OD8_Test : PlatformParams:getPlatformParams:Timestamp is 05/12/22 9:50:21

12/05/2022 14:52:47:422 DEBUG - 8A88ADDFC6408A4751C10C2E3468DBCE:/OD8_Test : License: Use the license server url in VPMS instead - https://10.100.5.25:52233/WebLM/LicenseServer

12/05/2022 14:52:47:422 DEBUG - 8A88ADDFC6408A4751C10C2E3468DBCE:/OD8_Test : Using license server - https://10.100.5.25:52233/WebLM/LicenseServer

12/05/2022 14:52:47:423  INFO - 8A88ADDFC6408A4751C10C2E3468DBCE:/OD8_Test : Using license check timeout :0

12/05/2022 14:52:47:929  INFO - 8A88ADDFC6408A4751C10C2E3468DBCE:/OD8_Test : Runtime :true

12/05/2022 14:52:47:929  INFO - 8A88ADDFC6408A4751C10C2E3468DBCE:/OD8_Test : IC :true

12/05/2022 14:52:47:929  INFO - 8A88ADDFC6408A4751C10C2E3468DBCE:/OD8_Test : CTI :true

12/05/2022 14:52:48:256 DEBUG - 8A88ADDFC6408A4751C10C2E3468DBCE:/OD8_Test : Grace Period timer cleared

12/05/2022 14:52:48:257 DEBUG - 8A88ADDFC6408A4751C10C2E3468DBCE:/OD8_Test : License refresh timer started

12/05/2022 14:52:48:259  INFO - 8A88ADDFC6408A4751C10C2E3468DBCE:/OD8_Test : MessageType is speech

12/05/2022 14:52:48:398  INFO - 8A88ADDFC6408A4751C10C2E3468DBCE:/OD8_Test : Using SCESession 8A88ADDFC6408A4751C10C2E3468DBCE:/OD8_Test servlet : A1

Hi. Do you see any error message on logs ? It sounds a platform -related behaviour.

I found it in catalina.out, but there is no timestamp, so i write where the delay was:

Start of the session

VPAppLogClientBase::setEPMWebServicesClient -->

VPAppLogClientBase:setEPMWebServicesClient: setting epmWebSErvicesClientBase instance first time

VPAppLogClientBase:getAxis2PrimaryUrl: axis2 vpms primary url: 10.100.5.20

VPAppLogClientBase:getReportUrl() - report URL is: disabled

ReportWriter:setEPMWebServicesClient(): https://10.100.5.20/axis2/services/VPAppLogService

VPAppLogClientBase.getEPMWebServicesCientBaseFromMapForAlarm() - reportURL: https://10.100.5.20/axis2/services/VPAppLogService

3 sec delay...

VPAppLogClientBase.getEPMWebServicesCientBaseFromMapForAlarm() - not found EPMWebServicesClientBase instance for https://10.100.5.20/axis2/services/VPAppLogService

VPAppLogClientBase.setEPMWebServicesClientBaseForAlarm() - add EPMWebServicesClientBase for https://10.100.5.20/axis2/services/VPAppLogService

BatchLogWriterBase:isLogWriterThreadRunning: GUID:  reportURL: https://10.100.5.20/axis2/services/VPAppLogService

BatchLogWriterBase:isLogWriterThreadRunning: false

BatchLogWriterBase:isLogWriterThreadCDRSDRRunning: GUID:  reportURL: https://10.100.5.20/axis2/services/VPAppLogService

BatchLogWriterBase:isLogWriterThreadCDRSDRRunning: false

VPAppLogClientBase:setEPMWebServicesClient: batchLogWriter and batchLogWriterCDRSDR threads are not running: https://10.100.5.20/axis2/services/VPAppLogService save to the map

VPAppLogClientBase::setEPMWebServicesClient <--

Hi. Is the app using any connector (ex. CTI/AES connector) ? The first call delay can be caused by an internal connector.

There is no any connector.

According to logs in catalina out, the VPAppLogClientBase class in VPAppLogClient_8.1.1.jar does something which takes 3 seconds:

VPAppLogClientBase.getEPMWebServicesCientBaseFromMapForAlarm() - reportURL: https://10.100.5.20/axis2/services/VPAppLogService
...3 sec...
VPAppLogClientBase.getEPMWebServicesCientBaseFromMapForAlarm() - not found EPMWebServicesClientBase instance for https://10.100.5.20/axis2/services/VPAppLogService

Is it a normal behavior?
Can you test in in your lab? I did my test with pure OD 8.1.1 app, without any integration. The app doesn't do anything, just play an announcement. Made from scratch. Delay is only in 1st call after a Tomcat restart.

I could not replicate in my environment. I suggest to see the VXI logs ( $AVAYA_MPP_HOME/logs/process/VB) on AEP to figure out what is happening during these 3 secs.