Author Message
SandeepParvathreddy
Joined: Dec 6, 2013
Messages: 86
Offline
Hi team,

Could you please advice on the following issues:

Setup Details
Application Server Tomcat: Apache Tomcat/7.0.67
Java: 1.7.0_80-b15 (Oracle Corporation)
OS: Linux 3.10.0-327.36.2.el7.x86_64 - amd64
Orchestration Designer: 07.01.08.04

Experience Portal Manager( 10.250.96.34)
Version: 6.0.2.0.0501


a. IVR application is not able to grab runtimelicense and due to which call is terminated prematurely.
As the trace log snippet for a call shows, license check failed and hence subsequent calls start to fail.

Trace log snippet
29/09/2016 11:05:57:215 INFO - 435A406645841C4AAED887A90D8A26DC:/IVR101 : SCESession bound to HttpSession 435A406645841C4AAED887A90D8A26DC
29/09/2016 11:05:57:216 INFO - 435A406645841C4AAED887A90D8A26DC:/IVR101 : Browser Version 0.0, terminationURL enabled : false
29/09/2016 11:05:57:216 DEBUG - 435A406645841C4AAED887A90D8A26DC:/IVR101 : PlatformParams:getPlatformParams: __VPVarGlobalDate is null
29/09/2016 11:05:57:216 DEBUG - 435A406645841C4AAED887A90D8A26DC:/IVR101 : PlatformParams:getPlatformParams:Timestamp is 01/01/70 4:00:00
29/09/2016 11:05:57:216 INFO - 435A406645841C4AAED887A90D8A26DC:/IVR101 : Using SCESession 435A406645841C4AAED887A90D8A26DC:/IVR101 servlet : Start
29/09/2016 11:05:57:219 INFO - 435A406645841C4AAED887A90D8A26DC:/IVR101 : ** Pushed Stack Frame [/IVR101]
29/09/2016 11:05:57:219 DEBUG - 435A406645841C4AAED887A90D8A26DC:/IVR101 : Creating variable [vdu] from factory [com.avaya.sce.runtime.connectivity.ic.pdc.VDUVariableFactory]
29/09/2016 11:05:57:220 DEBUG - 435A406645841C4AAED887A90D8A26DC:/IVR101 : Creating variable [vdu_cache] from factory [com.avaya.sce.runtime.connectivity.ic.pdc.VDUCacheVariableFactory]
29/09/2016 11:05:57:222 INFO - 435A406645841C4AAED887A90D8A26DC:/IVR101 : runtime_platform : Experience Portal
29/09/2016 11:05:57:222 INFO - 435A406645841C4AAED887A90D8A26DC:/IVR101 : runtime_asr : Desktop Microsoft Speech SAPI
29/09/2016 11:05:57:222 DEBUG - 435A406645841C4AAED887A90D8A26DC:/IVR101 : Refreshing License
29/09/2016 11:05:57:222 INFO - 435A406645841C4AAED887A90D8A26DC:/IVR101 : Acquiring Avaya Platform runtime license
29/09/2016 11:05:57:222 INFO - 435A406645841C4AAED887A90D8A26DC:/IVR101 : Using license check timeout :1
29/09/2016 11:05:57:236 INFO - 435A406645841C4AAED887A90D8A26DC:/IVR101 : Runtime :false
29/09/2016 11:05:57:236 INFO - 435A406645841C4AAED887A90D8A26DC:/IVR101 : IC :false
29/09/2016 11:05:57:236 INFO - 435A406645841C4AAED887A90D8A26DC:/IVR101 : CTI :false
29/09/2016 11:05:57:243 DEBUG - 435A406645841C4AAED887A90D8A26DC:/IVR101 : License is bad, allowing grace period
29/09/2016 11:05:57:243 DEBUG - 435A406645841C4AAED887A90D8A26DC:/IVR101 : License refresh timer started
29/09/2016 11:05:57:245 INFO - 435A406645841C4AAED887A90D8A26DC:/IVR101 : MessageType is speech
29/09/2016 11:06:12:463 INFO - 435A406645841C4AAED887A90D8A26DC:/IVR101 : Using SCESession 435A406645841C4AAED887A90D8A26DC:/IVR101 servlet : GetInitVariables

In order to rectify this issue, customer accesses runtimeconfig, visits license server page and just presses “Update” button (without doing any changes).
In some cases, this resolves the issue and the calls do not experience license check failure. For remaining cases, customer has to bounce (restart) tomcat in order to fix this problem temporarily.

b. At the same time, certificate errors are also experienced.
This is just any observation from our side, as this issue is happening around same time when the bad license error comes up. Below trace log snippet shows license failure. After this, call does not progress.

Trace Log Snippet
27/10/2016 10:45:27:834 INFO - CBD0589D3B3C6771E0F232159AFB5B95:/AppointmentCenter_8007622 : Storing :shareduui___id to complex: shareduui:id as [unknown]
27/10/2016 10:45:27:834 INFO - CBD0589D3B3C6771E0F232159AFB5B95:/AppointmentCenter_8007622 : Storing :shareduui___value to complex: shareduui:value as [unknown]
27/10/2016 10:45:27:835 DEBUG - CBD0589D3B3C6771E0F232159AFB5B95:/AppointmentCenter_8007622 : ICCommand.execute: Talking to ICC using URL: https://au754.etisalat.corp.ae:8443/icconnector/RequestWebID
27/10/2016 10:45:27:835 DEBUG - CBD0589D3B3C6771E0F232159AFB5B95:/AppointmentCenter_8007622 : ICCommand.execute: setting session cookie to CBD0589D3B3C6771E0F232159AFB5B95:/AppointmentCenter_8007622
27/10/2016 10:45:27:866 INFO - CBD0589D3B3C6771E0F232159AFB5B95:/AppointmentCenter_8007622 : Capturing exception [com.avaya.sce.runtimecommon.SCERuntimeException]. Message [ICNewCall:sun.security.validator.ValidatorException: No trusted certificate found]
27/10/2016 10:45:27:867 INFO - CBD0589D3B3C6771E0F232159AFB5B95:/AppointmentCenter_8007622 : Capturing exception [com.avaya.sce.runtimecommon.SCERuntimeException]. Message [Error loading PluggableConnectorInitialize class [com.avaya.sce.runtime.connectivity.ic.pdc.ICConnectorInit] for initialVariablesPosted com.avaya.sce.runtimecommon.SCERuntimeException: ICNewCall:sun.security.validator.ValidatorException: No trusted certificate found
**** Root Cause
com.avaya.sce.runtimecommon.SCERuntimeException: ICNewCall:sun.security.validator.ValidatorException: No trusted certificate found
at com.avaya.sce.runtimecommon.SCESession.throwRTException(SCESession.java:2316)
at com.avaya.sce.runtime.connectivity.ic.web.ICCommand.setError(ICCommand.java:291)
at com.avaya.sce.runtime.connectivity.ic.web.ICCommand.executeCommand(ICCommand.java:142)
at com.avaya.sce.runtime.connectivity.ic.pdc.ICConnectorInit.initialVariablesPosted(ICConnectorInit.java:264)
at com.avaya.sce.runtime.SCEServlet.processRequest(SCEServlet.java:585)
at com.avaya.sce.runtime.AppServlet.processRequest(AppServlet.java:76)
at com.avaya.sce.runtime.SCEServlet.requestHandler(SCEServlet.java:285)
at com.avaya.sce.runtime.SCEServlet.doPost(SCEServlet.java:190)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:650)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:731)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:303)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:220)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:122)
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:505)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:169)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103)
at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:956)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:423)
at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1079)
at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:625)
at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:318)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:745)
]
27/10/2016 10:45:27:870 ERROR - CBD0589D3B3C6771E0F232159AFB5B95:/AppointmentCenter_8007622 : session id:AJM1-2016301064533-18 | Error processing request

Upon this error, customer bounces tomcat to fix this issue temporarily.

c.For some instances, it is observed that IVR application is not grabbing the license that is configured in runtimeconfig. Instead it is referring to the license URL that is configured in EPM.
Please see the log snippet below:
Trace Log Snippet
10/08/2016 11:00:00:696 INFO - C9EBB439F1598CA3044F670E43F4DFA2:/IVR101 : SCESession bound to HttpSession C9EBB439F1598CA3044F670E43F4DFA2
10/08/2016 11:00:00:708 INFO - C9EBB439F1598CA3044F670E43F4DFA2:/IVR101 : Browser Version 2.1.4, terminationURL enabled : true
10/08/2016 11:00:00:708 DEBUG - C9EBB439F1598CA3044F670E43F4DFA2:/IVR101 : PlatformParams:getPlatformParams: __VPVarGlobalDate is 1379238441822
10/08/2016 11:00:00:708 DEBUG - C9EBB439F1598CA3044F670E43F4DFA2:/IVR101 : PlatformParams:getPlatformParams:Timestamp is 09/15/13 13:47:21
10/08/2016 11:00:00:708 DEBUG - C9EBB439F1598CA3044F670E43F4DFA2:/IVR101 : PlatformParams: get global parameters from VPMS...
10/08/2016 11:00:01:724 DEBUG - C9EBB439F1598CA3044F670E43F4DFA2:/IVR101 : PlatformParams: AppRuntimeVarsResponse.getGlobalAppRuntimeVars returns status - success
10/08/2016 11:00:01:724 DEBUG - C9EBB439F1598CA3044F670E43F4DFA2:/IVR101 : PlatformParams: get parameter|value - __VPLicenseServerURL|https://10.250.96.34:8443/WebLM/LicenseServer
10/08/2016 11:00:01:725 INFO - C9EBB439F1598CA3044F670E43F4DFA2:/IVR101 : Using SCESession C9EBB439F1598CA3044F670E43F4DFA2:/IVR101 servlet : Start
10/08/2016 11:00:01:734 INFO - C9EBB439F1598CA3044F670E43F4DFA2:/IVR101 : ** Pushed Stack Frame [/IVR101]
10/08/2016 11:00:01:734 DEBUG - C9EBB439F1598CA3044F670E43F4DFA2:/IVR101 : Creating variable [vdu] from factory [com.avaya.sce.runtime.connectivity.ic.pdc.VDUVariableFactory]
10/08/2016 11:00:01:735 DEBUG - C9EBB439F1598CA3044F670E43F4DFA2:/IVR101 : Creating variable [vdu_cache] from factory [com.avaya.sce.runtime.connectivity.ic.pdc.VDUCacheVariableFactory]
10/08/2016 11:00:01:736 INFO - C9EBB439F1598CA3044F670E43F4DFA2:/IVR101 : Storing :session___sessionid to complex: session:sessionid as [AJM1-2016223070000-27]
10/08/2016 11:00:01:739 INFO - C9EBB439F1598CA3044F670E43F4DFA2:/IVR101 : runtime_platform : Experience Portal
10/08/2016 11:00:01:740 INFO - C9EBB439F1598CA3044F670E43F4DFA2:/IVR101 : runtime_asr : SRGS-Literals
10/08/2016 11:00:01:742 INFO - C9EBB439F1598CA3044F670E43F4DFA2:/IVR101 : MessageType is speech
10/08/2016 11:00:01:782 INFO - C9EBB439F1598CA3044F670E43F4DFA2:/IVR101 : Using SCESession C9EBB439F1598CA3044F670E43F4DFA2:/IVR101 servlet : GetInitVariables



WebLM Configuration
Configured in EPM => https://10.250.96.34:8443/WebLM/LicenseServer -- local weblm hosting EP lic
Configured in runtimeconfig => https://10.51.165.93:52233 -- master webLM hosting runtime lic


An Observation
Whenever the line "Browser Version 2.1.4" is seen for a call in app trace, the below line is also seen
PlatformParams: get parameter|value - __VPLicenseServerURL|https://10.250.96.34:8443/WebLM/LicenseServer
Whereas,
For the line "Browser Version 0.0", the below line is seen (but not always).
Acquiring Avaya Platform runtime license
We need your expertise to comment on this whether our observation is correct or is it something unrelated to license issues.

Attached the app trace for review.

Please advise . Thanks.
Filename trace.zip [Disk] Download
WilsonYu
Joined: Nov 6, 2013
Messages: 3950
Offline
Duplicate of https://www.devconnectprogram.com/forums/posts/list/20303.page
Go to:   
Mobile view