| Message |
|
[+]
Avaya Orchestration Designer
» Delay in first call after a Tomcat restart, 17/05/2022 07:52:33
» Go to message
|
|
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.
|
 |
|
[+]
Avaya Orchestration Designer
» Delay in first call after a Tomcat restart, 12/05/2022 10:10:57
» Go to message
|
|
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 <--
|
|
|
[+]
Avaya Orchestration Designer
» Delay in first call after a Tomcat restart, 12/05/2022 09:11:26
» Go to message
|
|
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
|
|
|
[+]
Avaya Orchestration Designer
» ICConnector utf-8, 27/01/2022 07:13:22
» Go to message
|
|
You are right. The problem was with Tomcat JVM.
Adding -Dfile.encoding=UTF-8 Java option to Tomcat service script solved the problem.
|
|
|
[+]
Avaya Orchestration Designer
» ICConnector utf-8, 14/01/2022 07:16:56
» Go to message
|
|
Hi,
We have an issue with ICConnector. We set/get EDU fields containing values with special national characters. The setting EDU field works fine. When we get the same EDU field, the special characters go wrong. We have analyzed the AIC integration components and found the followings:
- The AIC HTTPConnector sends the response with correct UTF-8 charaters, however there is no header for charset in the HTTP message. Here is the request/response TCP messages captured by Wireshark:
ICConnector get EDU request:
POST /httpvox.htm HTTP/1.1
Cache-Control: no-cache
Pragma: no-cache
User-Agent: Java/1.8.0_152
Host: 10.12.85.100:9170
Accept: text/html, image/gif, image/jpeg, *; q=.2, */*; q=.2
Connection: keep-alive
Content-type: application/x-www-form-urlencoded
Content-Length: 114
action=start_script&script=httpvox.iccmd&command=getedu&eduid=61e1755f000000000a0c5164234a0002&test_field_1=%22%22
Response from AIC HTTPConnector:
HTTP/1.0 200 OK
Date: p?ntek, 14-jan.-22 13:06:42 GMT
Server: Avaya HTTP Channel
MIME-version: 1.0
Content-Type: text/html
Content-Length: 169
<count>4</count><loginid></loginid><test_field_1>árvízt?r? tükörfúrógép</test_field_1><sys_scripttimeout>600</sys_scripttimeout><returncode>SUCCESS</returncode>
- The problem starts here, the response seems wrong in ICConnector log, and the value is sent back to OD incorrectly:
14/01/2022 13:54:26:231 DEBUG - ICConnectorServer.httpRequest: url is:http://10.12.85.100:9170/httpvox.htm
14/01/2022 13:54:26:231 DEBUG - ICConnectorServer.httpRequest: posting:action=start_script&script=httpvox.iccmd&command=getedu&eduid=61e1727f000000000a0c5164234a0002&test_field_1=%22%22
14/01/2022 13:54:26:493 DEBUG - ICConnectorServer.httpRequest: response took:262ms for URL:http://10.12.85.100:9170/httpvox.htm
14/01/2022 13:54:26:493 DEBUG - ICConnectorServer.httpRequest: responseCode:200
14/01/2022 13:54:26:493 DEBUG - ICConnectorServer.httpRequest: response is:<count>4</count><loginid></loginid><test_field_1>??rv??zt??r?? t??k??rf??r??g??p</test_field_1><sys_scripttimeout>600</sys_scripttimeout><returncode>SUCCESS</returncode></body></html>
14/01/2022 13:54:26:493 DEBUG - ICConnectorManager.jobCompleted: Response back: responseType=getvdu.response&reqID=76-996&field="test_field_1"|"??rv??zt??r?? t??k??rf??r??g??p" for req: 76-996
version:
ICConnector 07.10.12.02
AIC HTTPConnector 7.3.8.64
Regards,
Istvan
|
|
|
[+]
Avaya Orchestration Designer
» OD local module call first node is replaced by a previous node at runtime, 22/01/2016 08:53:34
» Go to message
|
|
In the meantime i found a workaround: i added an empty VXML form to that module which previously had no any.
This solved the issue.
|
|
|
[+]
Avaya Orchestration Designer
» OD local module call first node is replaced by a previous node at runtime, 22/01/2016 02:09:55
» Go to message
|
|
It seems this Tomcat setting didn't help. I tried the setting in the server.xml of Tomcat this way:
<Connector port="8080" protocol="HTTP/1.1"
connectionTimeout="20000" connectionLinger="10000"
redirectPort="8443" />
I tried first with value 1, then 10, then i found that it is milliseconds. i tried 1000, then 10000, but it didn't help. Of course, each time i restarted Tomcat.
Did i do it right?
|
|
|
[+]
Avaya Orchestration Designer
» OD local module call first node is replaced by a previous node at runtime, 20/01/2016 14:19:08
» Go to message
|
|
Hi,
This weird problem occurs in the following environment:
AEP 7.0.2.0303
AAOD 7.0.1.0804
There are many local type module calls in the application. Sometimes when a local module is started, instead of its first node, the OD starts a previous node (servlet).
Example trace log:
20/01/2016 14:06:38:085 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Using SCESession 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main servlet : SetLog_SERV_FRAUD
20/01/2016 14:06:38:085 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : ** Popped Stack Frame [/Topnet_Greeting]
20/01/2016 14:06:38:085 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Module Local Call to : [WriteLog/Start]
20/01/2016 14:06:38:085 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : ** Pushed Stack Frame [/WriteLog]
20/01/2016 14:06:38:085 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : request url copy is [http://lvphavyas2:8080/Topnet_Postpaid/SetLog_SERV_FRAUD]
20/01/2016 14:06:38:085 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : location is [/WriteLog/Start?___DDSESSIONID=9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main]
20/01/2016 14:06:38:085 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : redirecting to [http://lvphavyas2:8080/WriteLog/Start?___DDSESSIONID=9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main]
20/01/2016 14:06:38:088 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Using SCESession 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main servlet : Start
20/01/2016 14:06:38:088 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Creating variable [vdu] from factory [com.avaya.sce.runtime.connectivity.ic.pdc.VDUVariableFactory]
20/01/2016 14:06:38:088 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Creating variable [vdu_cache] from factory [com.avaya.sce.runtime.connectivity.ic.pdc.VDUCacheVariableFactory]
20/01/2016 14:06:38:089 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Using SCESession 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main servlet : prepareLog
20/01/2016 14:06:38:089 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : session id:xlvphavympp1-2016020130633-7 | WriteLog:prepareLog | _____Input params: Service=SERV_FRAUD | Event=-
20/01/2016 14:06:38:089 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : session id:xlvphavympp1-2016020130633-7 | WriteLog:prepareLog | _____Input param Event is not set, skip logging
20/01/2016 14:06:38:089 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Using SCESession 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main servlet : writeLog
20/01/2016 14:06:38:089 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Using SCESession 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main servlet : DummyNode
20/01/2016 14:06:38:089 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : session id:xlvphavympp1-2016020130633-7 | WriteLog:DummyNode | _____
20/01/2016 14:06:38:089 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Using SCESession 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main servlet : End
20/01/2016 14:06:38:089 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : request url copy is [http://lvphavyas2:8080/WriteLog/End]
20/01/2016 14:06:38:089 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : location is [/Topnet_Postpaid/DB_Call_TOP_CHECK_FRAUD?___DDSESSIONID=9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main]
20/01/2016 14:06:38:089 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : redirecting to [http://lvphavyas2:8080/Topnet_Postpaid/DB_Call_TOP_CHECK_FRAUD?___DDSESSIONID=9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main]
20/01/2016 14:06:38:091 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Using SCESession 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main servlet : DB_Call_TOP_CHECK_FRAUD
20/01/2016 14:06:38:091 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : ** Popped Stack Frame [/WriteLog]
20/01/2016 14:06:38:091 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Assigning [vdu_cache:primary_ani] to [Call_TOP_CHECK_FRAUD:P_MSISDN]
20/01/2016 14:06:38:091 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : session id:xlvphavympp1-2016020130633-7 | Topnet_Postpaid:DB_Call_TOP_CHECK_FRAUD | _____ | Call_TOP_CHECK_FRAUD:P_MSISDN : 381xxxxxxxxx
20/01/2016 14:06:38:091 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Executing DB statement : [{ call VIP_IVR.TOP_CHECK_FRAUD ( ?, ?) }]
20/01/2016 14:06:38:134 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : session id:xlvphavympp1-2016020130633-7 | Topnet_Postpaid:DB_Call_TOP_CHECK_FRAUD | _____ | Call_TOP_CHECK_FRAUD:STATUS : 0
20/01/2016 14:06:38:134 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : [expression1] Expression [Call_TOP_CHECK_FRAUD:STATUS] String Equal [0]
20/01/2016 14:06:38:134 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : [expression2] Expression [vdu_cache:vip__DOT__suspended] String Equal [CA]
20/01/2016 14:06:38:134 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : [expression3] Expression [vdu_cache:vip__DOT__suspended] String Equal [CS]
20/01/2016 14:06:38:134 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Using SCESession 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main servlet : Mod_Collection
20/01/2016 14:06:38:134 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Overriding [VIP_Service/Start] with [Topnet_Collection/Start]
20/01/2016 14:06:38:134 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Module Local Call to : [Topnet_Collection/Start]
20/01/2016 14:06:38:134 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : ** Pushed Stack Frame [/Topnet_Collection]
20/01/2016 14:06:38:134 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : request url copy is [http://lvphavyas2:8080/Topnet_Postpaid/Mod_Collection]
20/01/2016 14:06:38:134 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : location is [/Topnet_Collection/Start?___DDSESSIONID=9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main]
20/01/2016 14:06:38:134 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : redirecting to [http://lvphavyas2:8080/Topnet_Collection/Start?___DDSESSIONID=9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main]
20/01/2016 14:06:38:136 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Using SCESession 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main servlet : DB_Call_TOP_CHECK_FRAUD
20/01/2016 14:06:38:137 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : ** Popped Stack Frame [/Topnet_Collection]
20/01/2016 14:06:38:137 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Not able to save posted variable information [AnyKey1___noinputcount]
20/01/2016 14:06:38:137 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Not able to save posted variable information [AnyKey1___nomatchcount]
20/01/2016 14:06:38:137 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Assigning [vdu_cache:primary_ani] to [Call_TOP_CHECK_FRAUD:P_MSISDN]
20/01/2016 14:06:38:137 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : session id:xlvphavympp1-2016020130633-7 | Topnet_Postpaid:DB_Call_TOP_CHECK_FRAUD | _____ | Call_TOP_CHECK_FRAUD:P_MSISDN : 381xxxxxxxxx
20/01/2016 14:06:38:137 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Executing DB statement : [{ call VIP_IVR.TOP_CHECK_FRAUD ( ?, ?) }]
20/01/2016 14:06:38:179 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : session id:xlvphavympp1-2016020130633-7 | Topnet_Postpaid:DB_Call_TOP_CHECK_FRAUD | _____ | Call_TOP_CHECK_FRAUD:STATUS : 0
20/01/2016 14:06:38:179 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : [expression1] Expression [Call_TOP_CHECK_FRAUD:STATUS] String Equal [0]
20/01/2016 14:06:38:179 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : [expression2] Expression [vdu_cache:vip__DOT__suspended] String Equal [CA]
20/01/2016 14:06:38:179 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : [expression3] Expression [vdu_cache:vip__DOT__suspended] String Equal [CS]
20/01/2016 14:06:38:179 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Using SCESession 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main servlet : Mod_Collection
20/01/2016 14:06:38:179 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Overriding [VIP_Service/Start] with [Topnet_Collection/Start]
20/01/2016 14:06:38:179 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Module Local Call to : [Topnet_Collection/Start]
20/01/2016 14:06:38:179 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : ** Pushed Stack Frame [/Topnet_Collection]
20/01/2016 14:06:38:180 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : request url copy is [http://lvphavyas2:8080/Topnet_Postpaid/Mod_Collection]
20/01/2016 14:06:38:180 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : location is [/Topnet_Collection/Start?___DDSESSIONID=9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main]
20/01/2016 14:06:38:180 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : redirecting to [http://lvphavyas2:8080/Topnet_Collection/Start?___DDSESSIONID=9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main]
20/01/2016 14:06:38:182 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Using SCESession 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main servlet : Start
20/01/2016 14:06:38:182 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Creating variable [vdu] from factory [com.avaya.sce.runtime.connectivity.ic.pdc.VDUVariableFactory]
20/01/2016 14:06:38:182 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Creating variable [vdu_cache] from factory [com.avaya.sce.runtime.connectivity.ic.pdc.VDUCacheVariableFactory]
20/01/2016 14:06:38:182 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Using SCESession 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main servlet : SetLog_SERV_COLL
There is another system with AEP 6 and OD 6, very same application structure, and it works fine long ago.
Is it a known issue maybe? Please advise.
|
|
|
[+]
Avaya Orchestration Designer
» VXML session output values are not received by CCXML session, 21/08/2015 08:20:15
» Go to message
|
|
We have Dialog Designer 5.1 sp2 and Voice Portal 5.1 sp1.
We have a CCXML application which makes outbound call. The outbound application is a Dialog Designer application, and it seems sometimes the output parameters (ContactResult in our case) of DD app are not received by CCXML session at dialog.exit event. Here is how the CCXML gets output:
<transition state="DialogOutbound" event="dialog.exit">
<log expr="'_____' + state + ' -- ' + event$.name"/>
<log expr="'_____ContactResult=' + event$.values.ContactResult"/>
<assign name="CONTACT_RESULT" expr="event$.values.ContactResult"/>
It is strange, as on the same server the value is mostly received correctly, but sometimes not. The ratio is approx. 7:1.
We printed out VXML to trace log on DD side, the value is sent correctly:
21/08/2015 12:49:16,169 DEBUG - C6A45947638C7279717C5E6BD34A44E1:/Engine_Main : *** Reply for [/Engine_Main/Return] ***
21/08/2015 12:49:16,169 DEBUG - C6A45947638C7279717C5E6BD34A44E1:/Engine_Main : 0:<?xml version="1.0" encoding="UTF-8"?>
1:<vxml version="2.1" xmlns="http://www.w3.org/2001/vxml" xml:lang="hr-hr">
2:<meta name="author" content="Avaya Dialog Designer"/>
3:<meta name="runtime-version" content="05.01.15.03"/>
4:<meta name="runtimecommon-version" content="05.01.15.03"/>
5:<meta name="copyright" content="Copyright (c) 2002-2010, Avaya"/>
6:<var name="_avayaExitReason" expr="''"/>
7:<var name="_avayaExitInfo1" expr="''"/>
8:<var name="_avayaExitInfo2" expr="''"/>
9:<var name="_avayaExitCustomerId" expr="''"/>
10:<var name="_avayaExitPreferredPath" expr="'1'"/>
11:<var name="_avayaExitTopic" expr="''"/>
12:<form id="Return">
13:<block>
14:<var name="ContactResult" expr="'13'"/>
15:<var name="RequestedTime" expr="''"/>
16:<exit namelist="ContactResult RequestedTime _avayaExitReason _avayaExitInfo1 _avayaExitInfo2 _avayaExitCustomerId _avayaExitPreferredPath _avayaExitTopic"/>
17:</block>
18:</form>
19:</vxml>
20:
21/08/2015 12:49:16,172 INFO - C6A45947638C7279717C5E6BD34A44E1:/Engine_Main : Removing session from AvayaSessionTermination Servlet
Here is the CCXML log of the same session:
@2015-08-21 12:49:16,268||FINE|CXI|26605|Session=tmobmpp3-2015233104820-7|CXI Diagnostic: (Interpreter::log_element) <label='', expr='_____DialogOutbound -- dialog.exit'>|tmobmpp3####
@2015-08-21 12:49:16,268||FINE|CXI|26605|Session=tmobmpp3-2015233104820-7|Sending message of type: AppLog & size: 76|tmobmpp3####
@2015-08-21 12:49:16,268||FINE|CXI|26605|Session=tmobmpp3-2015233104820-7|CXI Diagnostic: (Interpreter::log_element) <label='', expr='_____ContactResult=undefined'>|tmobmpp3####
@2015-08-21 12:49:16,268||FINE|CXI|26605|Session=tmobmpp3-2015233104820-7|Sending message of type: AppLog & size: 70|tmobmpp3####
@2015-08-21 12:49:16,268||FINE|CXI|26605|Session=tmobmpp3-2015233104820-7|CXI Diagnostic: (Interpreter::assign_element) <name='CONTACT_RESULT', expr='event$.values.ContactResult'>|tmobmpp3####
And here is a VXML and CCXML logs of a correctly received value from another call on same servers:
21/08/2015 10:53:37,483 DEBUG - 168FF2688483F67D8B67BC7E8BE69E88:/Engine_Main : *** Reply for [/Engine_Main/Return] ***
21/08/2015 10:53:37,483 DEBUG - 168FF2688483F67D8B67BC7E8BE69E88:/Engine_Main : 0:<?xml version="1.0" encoding="UTF-8"?>
1:<vxml version="2.1" xmlns="http://www.w3.org/2001/vxml" xml:lang="hr-hr">
2:<meta name="author" content="Avaya Dialog Designer"/>
3:<meta name="runtime-version" content="05.01.15.03"/>
4:<meta name="runtimecommon-version" content="05.01.15.03"/>
5:<meta name="copyright" content="Copyright (c) 2002-2010, Avaya"/>
6:<var name="_avayaExitReason" expr="''"/>
7:<var name="_avayaExitInfo1" expr="''"/>
8:<var name="_avayaExitInfo2" expr="''"/>
9:<var name="_avayaExitCustomerId" expr="''"/>
10:<var name="_avayaExitPreferredPath" expr="'1'"/>
11:<var name="_avayaExitTopic" expr="''"/>
12:<form id="Return">
13:<block>
14:<var name="ContactResult" expr="'13'"/>
15:<var name="RequestedTime" expr="''"/>
16:<exit namelist="ContactResult RequestedTime _avayaExitReason _avayaExitInfo1 _avayaExitInfo2 _avayaExitCustomerId _avayaExitPreferredPath _avayaExitTopic"/>
17:</block>
18:</form>
19:</vxml>
20:
21/08/2015 10:53:37,487 INFO - 168FF2688483F67D8B67BC7E8BE69E88:/Engine_Main : Removing session from AvayaSessionTermination Servlet
@2015-08-21 10:53:37,566||FINE|CXI|27192|Session=tmobmpp3-2015233085209-13|CXI Diagnostic: (Interpreter::log_element) <label='', expr='_____DialogOutbound -- dialog.exit'>|tmobmpp3####
@2015-08-21 10:53:37,566||FINE|CXI|27192|Session=tmobmpp3-2015233085209-13|Sending message of type: AppLog & size: 76|tmobmpp3####
@2015-08-21 10:53:37,566||FINE|CXI|27192|Session=tmobmpp3-2015233085209-13|CXI Diagnostic: (Interpreter::log_element) <label='', expr='_____ContactResult=13'>|tmobmpp3####
@2015-08-21 10:53:37,566||FINE|CXI|27192|Session=tmobmpp3-2015233085209-13|CXI Diagnostic: (Interpreter::assign_element) <name='CONTACT_RESULT', expr='event$.values.ContactResult'>|tmobmpp3####
Could you help us how to resolve this issue?
|
|
|
[+]
Avaya Orchestration Designer/Dialog Designer (Archive - Oct 2013 and earlier)
» Project name can't begin with number, 01/09/2011 17:00:47
» Go to message
|
|
We have been using project names like '85_1' for long time. It worked fine until DD 5.1 upgrade. Altough projects were successfully upgraded, but name starting with number is invalid if we want to create a new.
We can workaround it by creating like 'a100_1' and refactoring ot to '100_1', but it would be better if it would work like in previous versions.
|
|
|
[+]
Avaya Orchestration Designer/Dialog Designer (Archive - Oct 2013 and earlier)
» Support of <dialogterminate> hints, 09/12/2009 10:12:33
» Go to message
|
|
Are hints supported when using <dialogterminate> tag in CCXML?
If so, how to get them on VXML side?
|
|
|
[+]
Avaya Orchestration Designer/Dialog Designer (Archive - Oct 2013 and earlier)
» Does <send> work with targettype 'dialog'?, 09/12/2009 07:59:21
» Go to message
|
|
I tested <send> element in a ccxml application with targettype 'dialog'. The event is sent to VXML session, but the VXML eventhandler didn't catch it. I used eventname dialog.myevent.
Should it work? If so, how?
|
|
|
[+]
Avaya Orchestration Designer/Dialog Designer (Archive - Oct 2013 and earlier)
» NoClassDefFoundError: com/avaya/sce/runtime/tracking/ReportInfo, 27/07/2009 04:07:44
» Go to message
|
|
New information:
Issue occurred again. Now it is obvious, that "too many open files" error is the root cause.
I checked the open files, and i saw the application ddrt.properties and ddlog4j.properties files were open in a lot of instances 950 out of 1024 open files!
I will increase limit of open files, but it is only a temporary workaround. Is there possibility to influence on the behavior of opening and closing the ddrt.properties and ddlog4j.properties files from DD code or configuration?
|
|
|
[+]
Avaya Orchestration Designer/Dialog Designer (Archive - Oct 2013 and earlier)
» NoClassDefFoundError: com/avaya/sce/runtime/tracking/ReportInfo, 23/07/2009 09:45:03
» Go to message
|
|
One more symptom, but maybe it is an effect of the error:
- 13/07/2009 16:20:48 ERROR - Endpoint ServerSocket[addr=0.0.0.0/0.0.0.0,port=0,localport=8080] ignored exception: java.net.SocketException: Too many open files
I created a crontab job to watch number of files open by Tomcat process, and it is growing for a while from ~60 to ~350, and then increases suddenly back to ~60. Example:
07-23-2009 17:08:01 - Number of open files by Tomcat: 65
07-23-2009 17:09:01 - Number of open files by Tomcat: 87
07-23-2009 17:10:01 - Number of open files by Tomcat: 82
07-23-2009 17:11:02 - Number of open files by Tomcat: 98
07-23-2009 17:12:01 - Number of open files by Tomcat: 113
07-23-2009 17:13:01 - Number of open files by Tomcat: 113
07-23-2009 17:14:01 - Number of open files by Tomcat: 125
07-23-2009 17:15:01 - Number of open files by Tomcat: 132
07-23-2009 17:16:01 - Number of open files by Tomcat: 155
07-23-2009 17:17:01 - Number of open files by Tomcat: 165
07-23-2009 17:18:01 - Number of open files by Tomcat: 168
07-23-2009 17:19:01 - Number of open files by Tomcat: 202
07-23-2009 17:20:02 - Number of open files by Tomcat: 219
07-23-2009 17:21:01 - Number of open files by Tomcat: 242
07-23-2009 17:22:01 - Number of open files by Tomcat: 241
07-23-2009 17:23:01 - Number of open files by Tomcat: 252
07-23-2009 17:24:01 - Number of open files by Tomcat: 257
07-23-2009 17:25:01 - Number of open files by Tomcat: 283
07-23-2009 17:26:01 - Number of open files by Tomcat: 277
07-23-2009 17:27:01 - Number of open files by Tomcat: 288
07-23-2009 17:28:01 - Number of open files by Tomcat: 298
07-23-2009 17:29:01 - Number of open files by Tomcat: 322
07-23-2009 17:30:01 - Number of open files by Tomcat: 337
07-23-2009 17:31:01 - Number of open files by Tomcat: 91
07-23-2009 17:32:01 - Number of open files by Tomcat: 98
07-23-2009 17:33:01 - Number of open files by Tomcat: 114
.....
I checked what files are open, and the most of them are the ddrt.properties, and ddlog4j.properties of main application in multiple instances. This is an AIR platform system.
I checked a Voice Portal based system, and here there was no any *.properties file open. The number of open files are almost constant here, ~130-140.
|
|
|
[+]
Avaya Orchestration Designer/Dialog Designer (Archive - Oct 2013 and earlier)
» NoClassDefFoundError: com/avaya/sce/runtime/tracking/ReportInfo, 23/07/2009 04:56:17
» Go to message
|
|
The similar error happened 2 times since the first occurrence.
One was on 13 July, and another was on 19 July. The common symptoms are the followings:
- exception: "java.lang.NullPointerException at com.avaya.sce.runtimecommon.SCESession.getAvailableLanguages(SCESession.java:805)"
- exception: "com.avaya.sce.runtimecommon.SCERuntimeException: ICCallGone:Connection reset "
- very fast growing of catalina.out started with an exception: "Servlet.service() for servlet Start threw exception
java.lang.NullPointerException". After this exception, catalina.out is full of lines in a particular pattern layout which i don't know where comes from. Example:
550018363 [Thread-4] DEBUG IC.TraceWriter.ic - [ICC-test] ICConnectorCommon.Write: Writing to socket:pong
or
440270471 [http-8080-Processor22] ERROR org.apache.catalina.core.ContainerBase.[Catalina].[localhost].[/TComHR_Dispatcher].[Start] - Servlet.service() for servlet Start threw exception
java.lang.NullPointerException
The pattern may be: %r [%t] %p %c - %m%n
I don't know where it comes from, it shouldn't be here.
Also, these unnecessary lines are here multiple times (30-40x). Example:
440270471 [http-8080-Processor22] ERROR org.apache.catalina.core.ContainerBase.[Catalina].[localhost].[/TComHR_Dispatcher].[Start] - Servlet.service() for servlet Start threw exception
java.lang.NullPointerException
440270471 [http-8080-Processor22] ERROR org.apache.catalina.core.ContainerBase.[Catalina].[localhost].[/TComHR_Dispatcher].[Start] - Servlet.service() for servlet Start threw exception
java.lang.NullPointerException
440270471 [http-8080-Processor22] ERROR org.apache.catalina.core.ContainerBase.[Catalina].[localhost].[/TComHR_Dispatcher].[Start] - Servlet.service() for servlet Start threw exception
java.lang.NullPointerException
440270471 [http-8080-Processor22] ERROR org.apache.catalina.core.ContainerBase.[Catalina].[localhost].[/TComHR_Dispatcher].[Start] - Servlet.service() for servlet Start threw exception
java.lang.NullPointerException
440270471 [http-8080-Processor22] ERROR org.apache.catalina.core.ContainerBase.[Catalina].[localhost].[/TComHR_Dispatcher].[Start] - Servlet.service() for servlet Start threw exception
java.lang.NullPointerException
440270471 [http-8080-Processor22] ERROR org.apache.catalina.core.ContainerBase.[Catalina].[localhost].[/TComHR_Dispatcher].[Start] - Servlet.service() for servlet Start threw exception
java.lang.NullPointerException
440270471 [http-8080-Processor22] ERROR org.apache.catalina.core.ContainerBase.[Catalina].[localhost].[/TComHR_Dispatcher].[Start] - Servlet.service() for servlet Start threw exception
java.lang.NullPointerException
440270471 [http-8080-Processor22] ERROR org.apache.catalina.core.ContainerBase.[Catalina].[localhost].[/TComHR_Dispatcher].[Start] - Servlet.service() for servlet Start threw exception
java.lang.NullPointerException
440270471 [http-8080-Processor22] ERROR org.apache.catalina.core.ContainerBase.[Catalina].[localhost].[/TComHR_Dispatcher].[Start] - Servlet.service() for servlet Start threw exception
java.lang.NullPointerException
440270471 [http-8080-Processor22] ERROR org.apache.catalina.core.ContainerBase.[Catalina].[localhost].[/TComHR_Dispatcher].[Start] - Servlet.service() for servlet Start threw exception
java.lang.NullPointerException
440270471 [http-8080-Processor22] ERROR org.apache.catalina.core.ContainerBase.[Catalina].[localhost].[/TComHR_Dispatcher].[Start] - Servlet.service() for servlet Start threw exception
java.lang.NullPointerException
440270471 [http-8080-Processor22] ERROR org.apache.catalina.core.ContainerBase.[Catalina].[localhost].[/TComHR_Dispatcher].[Start] - Servlet.service() for servlet Start threw exception
java.lang.NullPointerException
440270471 [http-8080-Processor22] ERROR org.apache.catalina.core.ContainerBase.[Catalina].[localhost].[/TComHR_Dispatcher].[Start] - Servlet.service() for servlet Start threw exception
java.lang.NullPointerException
The last symptom causes disproportionately large catalina.out file, although the Tomcat doesn't crash all times, but DD is not working for approx 30 minutes. After a while, DD works without Tomcat restart, but catalina.out still grows very fast.
|
|
