Hi Team,

We are facing issue in outbound call, when customer is not answering or rejecting the call ,Outbound application getting response from CTI and working as expected.
But in the case of Customer number is busy, the OD-application not getting response from CTI and it’s getting session timeout and OD application closes the particular call session.
I am attaching Outbound application log for the reference. Please check and help us to get the response in case of customer is busy.

Please let us know if any other information required.

Scenario we tested:
Step-1: Make call to Agent VDN via CCXML and routed to free Agent & Agent answered.
Step-2: Play some prompt
Step-3: Put Agent call on hold
Step-4: Dial to customer using CTI.Dial node
Step-5: let the customer phone is in busy condition to reproduce the busy. Note: For testing no-answer, etc.. leave the phone un-answered.

Attached the OD feature release doc, in that doc its mentioned in case of busy, the failure state will be returned but we haven’t received failure either.

Can you post the trace.log in the aes connector too?

Please find below trace logs:-


2017-07-19 11:54:14,372 [localhost-startStop-1] INFO JTAPILoggingAdapter - Logging initialized correctly
2017-07-19 11:54:14,388 [localhost-startStop-1] INFO JTAPILoggingAdapter - Logging properties = {log4j.logger.com.avaya.jtapi.tsapi=INFO,defaultAppender, log4j.appender.defaultAppender.layout.ConversionPattern=%d [%t] %-5p %c{1} - %m%n, log4j.appender.defaultAppender=org.apache.log4j.RollingFileAppender, log4j.appender.defaultAppender.File=tsapi_trace.txt, log4j.appender.defaultAppender.MaxBackupIndex=9, log4j.appender.defaultAppender.layout=org.apache.log4j.PatternLayout, log4j.appender.defaultAppender.MaxFileSize=50MB}
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - System properties dump
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - java.runtime.name=Java(TM) SE Runtime Environment
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - sun.boot.library.path=C:\Program Files\Java\jre1.8.0_101\bin
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - java.vm.version=25.101-b13
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - shared.loader=
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - java.vm.vendor=Oracle Corporation
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - java.vendor.url=http://java.oracle.com/
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - path.separator=;
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - tomcat.util.buf.StringCache.byte.enabled=true
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - java.util.logging.config.file=C:\Program Files\Apache Software Foundation\Tomcat 8.0\conf\logging.properties
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - java.vm.name=Java HotSpot(TM) Client VM
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - file.encoding.pkg=sun.io
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - user.country=US
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - user.script=
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - sun.os.patch.level=Service Pack 2
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - tomcat.util.scan.StandardJarScanFilter.jarsToScan=log4j-core*.jar,log4j-taglib*.jar
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - java.vm.specification.name=Java Virtual Machine Specification
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - user.dir=C:\Program Files\Apache Software Foundation\Tomcat 8.0
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - java.runtime.version=1.8.0_101-b13
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - java.awt.graphicsenv=sun.awt.Win32GraphicsEnvironment
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - java.endorsed.dirs=C:\Program Files\Apache Software Foundation\Tomcat 8.0\endorsed
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - os.arch=x86
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - java.io.tmpdir=C:\Program Files\Apache Software Foundation\Tomcat 8.0\temp
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - line.separator=

2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - java.vm.specification.vendor=Oracle Corporation
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - java.naming.factory.url.pkgs=org.apache.naming
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - user.variant=
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - java.util.logging.manager=org.apache.juli.ClassLoaderLogManager
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - os.name=Windows Server 2008
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - sun.jnu.encoding=Cp1252
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - java.library.path=C:\Program Files\Apache Software Foundation\Tomcat 8.0\bin;C:\Windows\Sun\Java\bin;C:\Windows\system32;C:\Windows;C:\ProgramData\Oracle\Java\javapath;C:\Windows\system32;C:\Windows;C:\Windows\System32\Wbem;C:\Windows\System32\WindowsPowerShell\v1.0\;c:\Program Files\Microsoft SQL Server\100\Tools\Binn\VSShell\Common7\IDE\;c:\Program Files\Microsoft SQL Server\100\Tools\Binn\;c:\Program Files\Microsoft SQL Server\100\DTS\Binn\;C:\Program Files\Windows Imaging\;C:\Program Files\Java\jre1.8.0_101\bin;.
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - java.specification.name=Java Platform API Specification
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - java.class.version=52.0
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - sun.management.compiler=HotSpot Client Compiler
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - os.version=6.0
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - user.home=C:\Windows\system32\config\systemprofile
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - catalina.useNaming=true
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - user.timezone=Asia/Calcutta
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - java.awt.printerjob=sun.awt.windows.WPrinterJob
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - file.encoding=Cp1252
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - java.specification.version=1.8
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - tomcat.util.scan.StandardJarScanFilter.jarsToSkip=bootstrap.jar,commons-daemon.jar,tomcat-juli.jar,annotations-api.jar,el-api.jar,jsp-api.jar,servlet-api.jar,websocket-api.jar,catalina.jar,catalina-ant.jar,catalina-ha.jar,catalina-storeconfig.jar,catalina-tribes.jar,jasper.jar,jasper-el.jar,ecj-*.jar,tomcat-api.jar,tomcat-util.jar,tomcat-util-scan.jar,tomcat-coyote.jar,tomcat-dbcp.jar,tomcat-jni.jar,tomcat-spdy.jar,tomcat-websocket.jar,tomcat-i18n-en.jar,tomcat-i18n-es.jar,tomcat-i18n-fr.jar,tomcat-i18n-ja.jar,tomcat-juli-adapters.jar,catalina-jmx-remote.jar,catalina-ws.jar,tomcat-jdbc.jar,tools.jar,commons-beanutils*.jar,commons-codec*.jar,commons-collections*.jar,commons-dbcp*.jar,commons-digester*.jar,commons-fileupload*.jar,commons-httpclient*.jar,commons-io*.jar,commons-lang*.jar,commons-logging*.jar,commons-math*.jar,commons-pool*.jar,jstl.jar,geronimo-spec-jaxrpc*.jar,wsdl4j*.jar,ant.jar,ant-junit*.jar,aspectj*.jar,jmx.jar,h2*.jar,hibernate*.jar,httpclient*.jar,jmx-tools.jar,jta*.jar,log4j*.jar,mail*.jar,slf4j*.jar,xercesImpl.jar,xmlParserAPIs.jar,xml-apis.jar,junit.jar,junit-*.jar,ant-launcher.jar,cobertura-*.jar,asm-*.jar,dom4j-*.jar,icu4j-*.jar,jaxen-*.jar,jdom-*.jar,jetty-*.jar,oro-*.jar,servlet-api-*.jar,tagsoup-*.jar,xmlParserAPIs-*.jar,xom-*.jar
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - catalina.home=C:\Program Files\Apache Software Foundation\Tomcat 8.0
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - java.class.path=C:\Program Files\Apache Software Foundation\Tomcat 8.0\bin\bootstrap.jar;C:\Program Files\Apache Software Foundation\Tomcat 8.0\bin\tomcat-juli.jar
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - user.name=WIN-DDRHAA1SGRK$
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - java.naming.factory.initial=org.apache.naming.java.javaURLContextFactory
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - package.definition=sun.,java.,org.apache.catalina.,org.apache.coyote.,org.apache.jasper.,org.apache.naming.,org.apache.tomcat.
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - java.vm.specification.version=1.8
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - java.home=C:\Program Files\Java\jre1.8.0_101
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - sun.arch.data.model=32
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - user.language=en
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - java.specification.vendor=Oracle Corporation
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - awt.toolkit=sun.awt.windows.WToolkit
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - java.vm.info=mixed mode
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - java.version=1.8.0_101
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - java.ext.dirs=C:\Program Files\Java\jre1.8.0_101\lib\ext;C:\Windows\Sun\Java\lib\ext
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - sun.boot.class.path=C:\Program Files\Java\jre1.8.0_101\lib\resources.jar;C:\Program Files\Java\jre1.8.0_101\lib\rt.jar;C:\Program Files\Java\jre1.8.0_101\lib\sunrsasign.jar;C:\Program Files\Java\jre1.8.0_101\lib\jsse.jar;C:\Program Files\Java\jre1.8.0_101\lib\jce.jar;C:\Program Files\Java\jre1.8.0_101\lib\charsets.jar;C:\Program Files\Java\jre1.8.0_101\lib\jfr.jar;C:\Program Files\Java\jre1.8.0_101\classes
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - server.loader=
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - java.vendor=Oracle Corporation
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - catalina.base=C:\Program Files\Apache Software Foundation\Tomcat 8.0
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - file.separator=\
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - java.vendor.url.bug=http://bugreport.sun.com/bugreport/
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - common.loader="${catalina.base}/lib","${catalina.base}/lib/*.jar","${catalina.home}/lib","${catalina.home}/lib/*.jar"
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - sun.io.unicode.encoding=UnicodeLittle
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - sun.cpu.endian=little
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - package.access=sun.,org.apache.catalina.,org.apache.coyote.,org.apache.jasper.,org.apache.tomcat.
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - sun.desktop=windows
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - sun.cpu.isalist=pentium_pro+mmx pentium_pro pentium+mmx pentium i486 i386 i86
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - Jtapi properties dump
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - keyStorePassword=****
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - traceFileCount=10
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - enableDelayInTermConnDropOnCstaFailed=false
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - maxWaitForSocket=20 seconds
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - errorFile=
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - timeoutForDelayInTermConnDropOnCstaFailed=2
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - debugLevel=1
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - 172.16.26.33=450
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - verifyServerCertificate=false
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - callConnectSendMultipleCallSnapshotRequests=false
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - useTlinkIP=0
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - errorFileCount=10
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - disableSimulationForCSTAOriginatedEvent=false
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - enableAuditDump=false
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - keyStoreLocation=
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - altTraceFile=tsapi_trace.txt
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - errorFileSize=50M
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - trustStoreLocation=
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - tsDevicePerformanceOptimization=false
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - trustStorePassword=****
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - maxThreadPoolSize=20
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - callCleanupRate=100 seconds
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - propertyRefreshRate=100 seconds
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - getServicesTimeout=10
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - disableTermConnDropOnCstaFailed=false
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - callCompletionTimeout=15 seconds
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - traceFileSize=50M
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO Tsapi - JTAPI Package Version: 6.3.3.27
2017-07-19 11:54:14,403 [localhost-startStop-1] INFO TsapiChannelOio - browser: GENERIC
2017-07-19 11:54:14,513 [localhost-startStop-1] INFO TsapiSession - Sent InvokeID 1 for TSProvider[#1]@1800cde
2017-07-19 11:54:14,528 [GetEventThread] INFO TsapiSession - Received invokeID 1 for TSProvider[#1]@1800cde
2017-07-19 11:54:14,528 [GetEventThread] INFO TSInvokeID - Handling INVOKE ID 1 for TSProvider[#1]@1800cde
2017-07-19 11:54:14,528 [GetEventThread] INFO TSInvokeID - DONE handling INVOKE ID 1 for TSProvider[#1]@1800cde
2017-07-19 11:54:14,544 [localhost-startStop-1] INFO TsapiSession - Sent InvokeID 2 for TSProvider[#1]@1800cde
2017-07-19 11:54:14,544 [localhost-startStop-1] INFO TsapiChannelOio - browser: GENERIC
2017-07-19 11:54:14,544 [localhost-startStop-1] INFO TsapiSession - Sent InvokeID 1 for TSProvider[#1]@1800cde
2017-07-19 11:54:14,606 [GetEventThread] INFO TsapiSession - Received invokeID 1 for TSProvider[#1]@1800cde
2017-07-19 11:54:14,606 [GetEventThread] INFO TSInvokeID - Handling INVOKE ID 1 for TSProvider[#1]@1800cde
2017-07-19 11:54:14,606 [GetEventThread] INFO TSInvokeID - DONE handling INVOKE ID 1 for TSProvider[#1]@1800cde
2017-07-19 11:54:14,606 [localhost-startStop-1] INFO TsapiSession - Sent InvokeID 2 for TSProvider[#1]@1800cde
2017-07-19 11:54:14,622 [GetEventThread] INFO TsapiEventQueue - Putting event CSTAEvent[ACSClientHeartbeatEvent]@2da2f5. EVENT Q SIZE = 1 MAX Q SIZE = 1 for TSProvider[#1]@1800cde
2017-07-19 11:54:14,622 [GetEventThread] INFO TsapiSession - Received invokeID 2 for TSProvider[#1]@1800cde
2017-07-19 11:54:14,622 [GetEventThread] INFO TSInvokeID - Handling INVOKE ID 2 for TSProvider[#1]@1800cde
2017-07-19 11:54:14,622 [GetEventThread] INFO TSInvokeID - DONE handling INVOKE ID 2 for TSProvider[#1]@1800cde
2017-07-19 11:54:14,700 [localhost-startStop-1] INFO TsapiSession - Sent InvokeID 3 for TSProvider[#1]@1800cde
2017-07-19 11:54:14,700 [DistributeCSTAEvent] INFO TsapiEventQueue - Getting event CSTAEvent[ACSClientHeartbeatEvent]@2da2f5 for TSProvider[#1]@1800cde
2017-07-19 11:54:14,700 [DistributeCSTAEvent] INFO TSEventHandler - Handling ACS_CLIENT_HEARTBEAT event for TSProvider[#1]@1800cde
2017-07-19 11:54:14,700 [DistributeCSTAEvent] INFO TsapiHeartbeatStatus - Enabling the TSAPI heartbeat with a heartbeat interval of 20 seconds.
2017-07-19 11:54:14,700 [DistributeCSTAEvent] INFO TSEventHandler - DONE handling ACS_CLIENT_HEARTBEAT event for TSProvider[#1]@1800cde
2017-07-19 11:54:14,715 [GetEventThread] INFO TsapiSession - Received invokeID 3 for TSProvider[#1]@1800cde
2017-07-19 11:54:14,715 [GetEventThread] INFO TSInvokeID - Handling INVOKE ID 3 for TSProvider[#1]@1800cde
2017-07-19 11:54:14,715 [GetEventThread] INFO TSInvokeID - DONE handling INVOKE ID 3 for TSProvider[#1]@1800cde
2017-07-19 11:54:14,715 [localhost-startStop-1] INFO TsapiSession - Sent InvokeID 4 for TSProvider[#1]@1800cde
2017-07-19 11:54:14,715 [GetEventThread] INFO TsapiSession - Received invokeID 4 for TSProvider[#1]@1800cde
2017-07-19 11:54:14,715 [GetEventThread] INFO TSInvokeID - Handling INVOKE ID 4 for TSProvider[#1]@1800cde
2017-07-19 11:54:14,715 [GetEventThread] INFO TSInvokeID - DONE handling INVOKE ID 4 for TSProvider[#1]@1800cde
2017-07-19 11:54:14,715 [localhost-startStop-1] INFO TsapiSession - Sent InvokeID 5 for TSProvider[#1]@1800cde
2017-07-19 11:54:14,731 [GetEventThread] INFO TsapiSession - Received invokeID 5 for TSProvider[#1]@1800cde
2017-07-19 11:54:14,731 [GetEventThread] INFO TSInvokeID - Handling INVOKE ID 5 for TSProvider[#1]@1800cde
2017-07-19 11:54:14,731 [GetEventThread] INFO SysStatHandler - Filter set at [ 0x97000000 < SF_INITIALIZING SF_MESSAGES_LOST SF_OVERLOAD_IMMINENT SF_OVERLOAD_REACHED SF_OVERLOAD_RELIEVED >]
2017-07-19 11:54:14,731 [GetEventThread] INFO TSInvokeID - DONE handling INVOKE ID 5 for TSProvider[#1]@1800cde
2017-07-19 11:54:14,762 [ProviderInitialization] INFO TsapiSession - Sent InvokeID 6 for TSProvider[#1]@1800cde
2017-07-19 11:54:14,762 [GetEventThread] INFO TsapiSession - Received invokeID 6 for TSProvider[#1]@1800cde
2017-07-19 11:54:14,762 [GetEventThread] INFO TSInvokeID - Handling INVOKE ID 6 for TSProvider[#1]@1800cde
2017-07-19 11:54:14,762 [GetEventThread] INFO TSInvokeID - DONE handling INVOKE ID 6 for TSProvider[#1]@1800cde
2017-07-19 11:54:14,762 [ProviderInitialization] INFO TsapiSession - Sent InvokeID 7 for TSProvider[#1]@1800cde
2017-07-19 11:54:14,762 [GetEventThread] INFO TsapiSession - Received invokeID 7 for TSProvider[#1]@1800cde
2017-07-19 11:54:14,762 [GetEventThread] INFO TSInvokeID - Handling INVOKE ID 7 for TSProvider[#1]@1800cde
2017-07-19 11:54:14,762 [GetEventThread] INFO TSInvokeID - DONE handling INVOKE ID 7 for TSProvider[#1]@1800cde
2017-07-19 11:54:14,840 [localhost-startStop-1] INFO TsapiSession - Sent InvokeID 8 for TSProvider[#1]@1800cde
2017-07-19 11:54:14,840 [GetEventThread] INFO TsapiSession - Received invokeID 8 for TSProvider[#1]@1800cde
2017-07-19 11:54:14,840 [GetEventThread] INFO TsapiEventQueue - Putting event CSTAEvent[ACSUniversalFailureConfEvent]@4503a2. EVENT Q SIZE = 1 MAX Q SIZE = 1 for TSProvider[#1]@1800cde
2017-07-19 11:54:14,840 [DistributeCSTAEvent] INFO TsapiEventQueue - Getting event CSTAEvent[ACSUniversalFailureConfEvent]@4503a2 for TSProvider[#1]@1800cde
2017-07-19 11:54:14,840 [DistributeCSTAEvent] INFO TSInvokeID - Handling INVOKE ID 8 for TSProvider[#1]@1800cde
2017-07-19 11:54:14,840 [DistributeCSTAEvent] INFO TSInvokeID - DONE handling INVOKE ID 8 for TSProvider[#1]@1800cde
2017-07-19 11:54:14,840 [localhost-startStop-1] INFO TSProviderImpl - TSProvider.shutdown - attempting shutdown
2017-07-19 11:54:14,840 [localhost-startStop-1] INFO TSProviderImpl - TSProvider.shutdown - Starting
2017-07-19 11:54:14,840 [localhost-startStop-1] INFO TsapiSession - Sent InvokeID 9 for TSProvider[#1]@1800cde
2017-07-19 11:54:14,840 [GetEventThread] INFO TsapiSession - Received invokeID 9 for TSProvider[#1]@1800cde
2017-07-19 11:54:14,840 [GetEventThread] INFO TSInvokeID - Handling INVOKE ID 9 for TSProvider[#1]@1800cde
2017-07-19 11:54:14,840 [GetEventThread] INFO SysStatHandler - Event monitoring was ended successfully
2017-07-19 11:54:14,840 [GetEventThread] INFO TSInvokeID - DONE handling INVOKE ID 9 for TSProvider[#1]@1800cde
2017-07-19 11:54:14,840 [localhost-startStop-1] INFO TsapiSession - Sent InvokeID 10 for TSProvider[#1]@1800cde
2017-07-19 11:54:14,856 [GetEventThread] INFO TsapiSession - Received invokeID 10 for TSProvider[#1]@1800cde
2017-07-19 11:54:14,856 [GetEventThread] INFO TSInvokeID - Handling INVOKE ID 10 for TSProvider[#1]@1800cde
2017-07-19 11:54:14,856 [GetEventThread] INFO TSInvokeID - DONE handling INVOKE ID 10 for TSProvider[#1]@1800cde
2017-07-19 11:54:14,856 [localhost-startStop-1] INFO Tsapi - tsapi.shutdown() called (inService = true) for TSProvider[#1]@1800cde
2017-07-19 11:54:14,856 [localhost-startStop-1] INFO TsapiSession - Sent InvokeID 11 for TSProvider[#1]@1800cde
2017-07-19 11:54:14,856 [localhost-startStop-1] INFO TSProviderImpl - TSProvider.shutdown - Done
2017-07-19 11:54:14,856 [localhost-startStop-1] INFO TSProviderImpl - TSProvider.shutdown - attempting shutdown
2017-07-19 11:54:14,856 [localhost-startStop-1] INFO TSProviderImpl - TSProvider.shutdown - already in shutdown, redundant call, returning.
2017-07-19 11:54:14,856 [localhost-startStop-1] INFO TSProviderImpl - TSProvider: version '6.3.3.27 [production build]', for TSProvider[#2]@952c78
2017-07-19 11:54:14,856 [localhost-startStop-1] INFO TSProviderImpl - TSProvider: calling acsOpenStream serverID=AVAYA#PEDCM7#CSTA#PEDAESVM33 loginID=nethu passwd=******* for TSProvider[#2]@952c78
2017-07-19 11:54:14,856 [localhost-startStop-1] INFO TsapiChannelOio - browser: GENERIC
2017-07-19 11:54:14,856 [localhost-startStop-1] INFO TsapiSession - Sent InvokeID 1 for TSProvider[#2]@952c78
2017-07-19 11:54:14,949 [GetEventThread] INFO TsapiSession - Received invokeID 1 for TSProvider[#2]@952c78
2017-07-19 11:54:14,949 [GetEventThread] INFO TSInvokeID - Handling INVOKE ID 1 for TSProvider[#2]@952c78
2017-07-19 11:54:14,949 [GetEventThread] INFO TSInvokeID - DONE handling INVOKE ID 1 for TSProvider[#2]@952c78
2017-07-19 11:54:14,949 [localhost-startStop-1] INFO TsapiSession - Sent InvokeID 2 for TSProvider[#2]@952c78
2017-07-19 11:54:14,949 [localhost-startStop-1] INFO TsapiChannelOio - browser: GENERIC
2017-07-19 11:54:14,949 [localhost-startStop-1] INFO TsapiSession - Sent InvokeID 1 for TSProvider[#2]@952c78
2017-07-19 11:54:14,949 [GetEventThread] INFO TsapiSession - Received invokeID 1 for TSProvider[#2]@952c78
2017-07-19 11:54:14,949 [GetEventThread] INFO TSInvokeID - Handling INVOKE ID 1 for TSProvider[#2]@952c78
2017-07-19 11:54:14,949 [GetEventThread] INFO TSInvokeID - DONE handling INVOKE ID 1 for TSProvider[#2]@952c78
2017-07-19 11:54:14,949 [localhost-startStop-1] INFO TsapiSession - Sent InvokeID 2 for TSProvider[#2]@952c78
2017-07-19 11:54:14,965 [GetEventThread] INFO TsapiEventQueue - Putting event CSTAEvent[ACSClientHeartbeatEvent]@cab712. EVENT Q SIZE = 1 MAX Q SIZE = 1 for TSProvider[#2]@952c78
2017-07-19 11:54:14,965 [GetEventThread] INFO TsapiSession - Received invokeID 2 for TSProvider[#2]@952c78
2017-07-19 11:54:14,965 [GetEventThread] INFO TSInvokeID - Handling INVOKE ID 2 for TSProvider[#2]@952c78
2017-07-19 11:54:14,965 [GetEventThread] INFO TSInvokeID - DONE handling INVOKE ID 2 for TSProvider[#2]@952c78
2017-07-19 11:54:14,965 [localhost-startStop-1] INFO TsapiSession - Sent InvokeID 3 for TSProvider[#2]@952c78
2017-07-19 11:54:14,965 [DistributeCSTAEvent] INFO TsapiEventQueue - Getting event CSTAEvent[ACSClientHeartbeatEvent]@cab712 for TSProvider[#2]@952c78
2017-07-19 11:54:14,965 [DistributeCSTAEvent] INFO TSEventHandler - Handling ACS_CLIENT_HEARTBEAT event for TSProvider[#2]@952c78
2017-07-19 11:54:14,965 [DistributeCSTAEvent] INFO TsapiHeartbeatStatus - Enabling the TSAPI heartbeat with a heartbeat interval of 20 seconds.
2017-07-19 11:54:14,965 [DistributeCSTAEvent] INFO TSEventHandler - DONE handling ACS_CLIENT_HEARTBEAT event for TSProvider[#2]@952c78
2017-07-19 11:54:14,965 [GetEventThread] INFO TsapiSession - Received invokeID 3 for TSProvider[#2]@952c78
2017-07-19 11:54:14,965 [GetEventThread] INFO TSInvokeID - Handling INVOKE ID 3 for TSProvider[#2]@952c78
2017-07-19 11:54:14,965 [GetEventThread] INFO TSInvokeID - DONE handling INVOKE ID 3 for TSProvider[#2]@952c78
2017-07-19 11:54:14,965 [localhost-startStop-1] INFO TsapiSession - Sent InvokeID 4 for TSProvider[#2]@952c78
2017-07-19 11:54:14,965 [GetEventThread] INFO TsapiSession - Received invokeID 4 for TSProvider[#2]@952c78
2017-07-19 11:54:14,965 [GetEventThread] INFO TSInvokeID - Handling INVOKE ID 4 for TSProvider[#2]@952c78
2017-07-19 11:54:14,965 [GetEventThread] INFO TSInvokeID - DONE handling INVOKE ID 4 for TSProvider[#2]@952c78
2017-07-19 11:54:14,965 [localhost-startStop-1] INFO TsapiSession - Sent InvokeID 5 for TSProvider[#2]@952c78
2017-07-19 11:54:14,965 [GetEventThread] INFO TsapiSession - Received invokeID 5 for TSProvider[#2]@952c78
2017-07-19 11:54:14,965 [GetEventThread] INFO TSInvokeID - Handling INVOKE ID 5 for TSProvider[#2]@952c78
2017-07-19 11:54:14,965 [GetEventThread] INFO SysStatHandler - Filter set at [ 0x97000000 < SF_INITIALIZING SF_MESSAGES_LOST SF_OVERLOAD_IMMINENT SF_OVERLOAD_REACHED SF_OVERLOAD_RELIEVED >]
2017-07-19 11:54:14,965 [GetEventThread] INFO TSInvokeID - DONE handling INVOKE ID 5 for TSProvider[#2]@952c78
2017-07-19 11:54:14,981 [localhost-startStop-1] INFO TSDevice - Constructing device TSDevice[4500]@80e7d9 with name 4500 for TSProvider[#2]@952c78
2017-07-19 11:54:14,981 [localhost-startStop-1] INFO TsapiSession - Sent InvokeID 6 for TSProvider[#2]@952c78
2017-07-19 11:54:14,996 [localhost-startStop-1] INFO TSDevice - getDeviceType() for TSDevice[4500]@80e7d9
2017-07-19 11:54:14,996 [localhost-startStop-1] INFO TSDevice - TSDevice[4500]@80e7d9 waiting for initialization to complete
2017-07-19 11:54:14,996 [ProviderInitialization] INFO TsapiSession - Sent InvokeID 7 for TSProvider[#2]@952c78
2017-07-19 11:54:15,012 [GetEventThread] INFO TsapiSession - Received invokeID 6 for TSProvider[#2]@952c78
2017-07-19 11:54:15,012 [GetEventThread] INFO TSInvokeID - Handling INVOKE ID 6 for TSProvider[#2]@952c78
2017-07-19 11:54:15,012 [GetEventThread] INFO TSDevice - Initialization complete for TSDevice TSDevice[4500]@80e7d9 - making values available - for TSProvider[#2]@952c78
2017-07-19 11:54:15,012 [GetEventThread] INFO TSInvokeID - DONE handling INVOKE ID 6 for TSProvider[#2]@952c78
2017-07-19 11:54:15,012 [GetEventThread] INFO TsapiSession - Received invokeID 7 for TSProvider[#2]@952c78
2017-07-19 11:54:15,043 [localhost-startStop-1] INFO TsapiSession - Sent InvokeID 8 for TSProvider[#2]@952c78
2017-07-19 11:54:15,043 [GetEventThread] INFO TSInvokeID - Handling INVOKE ID 7 for TSProvider[#2]@952c78
2017-07-19 11:54:15,043 [GetEventThread] INFO TSInvokeID - DONE handling INVOKE ID 7 for TSProvider[#2]@952c78
2017-07-19 11:54:15,043 [ProviderInitialization] INFO TsapiSession - Sent InvokeID 9 for TSProvider[#2]@952c78
2017-07-19 11:54:15,090 [GetEventThread] INFO TsapiSession - Received invokeID 9 for TSProvider[#2]@952c78
2017-07-19 11:54:15,090 [GetEventThread] INFO TSInvokeID - Handling INVOKE ID 9 for TSProvider[#2]@952c78
2017-07-19 11:54:15,090 [GetEventThread] INFO TSInvokeID - DONE handling INVOKE ID 9 for TSProvider[#2]@952c78
2017-07-19 11:54:15,105 [GetEventThread] INFO TsapiSession - Received invokeID 8 for TSProvider[#2]@952c78
2017-07-19 11:54:15,105 [GetEventThread] INFO TSInvokeID - Handling INVOKE ID 8 for TSProvider[#2]@952c78
2017-07-19 11:54:15,105 [GetEventThread] INFO TSInvokeID - DONE handling INVOKE ID 8 for TSProvider[#2]@952c78
2017-07-19 11:54:15,121 [localhost-startStop-1] INFO TsapiSession - Sent InvokeID 10 for TSProvider[#2]@952c78
2017-07-19 11:54:15,168 [GetEventThread] INFO TsapiSession - Received invokeID 10 for TSProvider[#2]@952c78
2017-07-19 11:54:15,168 [GetEventThread] INFO TsapiEventQueue - Putting event CSTAEvent[CSTAQueryAgentStateConfEvent]@3c5e3d. EVENT Q SIZE = 1 MAX Q SIZE = 1 for TSProvider[#2]@952c78
2017-07-19 11:54:15,168 [DistributeCSTAEvent] INFO TsapiEventQueue - Getting event CSTAEvent[CSTAQueryAgentStateConfEvent]@3c5e3d for TSProvider[#2]@952c78
2017-07-19 11:54:15,168 [DistributeCSTAEvent] INFO TSInvokeID - Handling INVOKE ID 10 for TSProvider[#2]@952c78
2017-07-19 11:54:15,168 [DistributeCSTAEvent] INFO TSInvokeID - DONE handling INVOKE ID 10 for TSProvider[#2]@952c78
2017-07-19 11:54:15,168 [localhost-startStop-1] INFO TsapiSession - Sent InvokeID 11 for TSProvider[#2]@952c78
2017-07-19 11:54:15,215 [GetEventThread] INFO TsapiSession - Received invokeID 11 for TSProvider[#2]@952c78
2017-07-19 11:54:15,215 [GetEventThread] INFO TSInvokeID - Handling INVOKE ID 11 for TSProvider[#2]@952c78
2017-07-19 11:54:15,215 [GetEventThread] INFO TSInvokeID - DONE handling INVOKE ID 11 for TSProvider[#2]@952c78
2017-07-19 11:54:15,215 [localhost-startStop-1] INFO TsapiSession - Sent InvokeID 12 for TSProvider[#2]@952c78
2017-07-19 11:54:15,261 [GetEventThread] INFO TsapiSession - Received invokeID 12 for TSProvider[#2]@952c78
2017-07-19 11:54:15,261 [GetEventThread] INFO TsapiEventQueue - Putting event CSTAEvent[CSTAQueryDndConfEvent]@1051245. EVENT Q SIZE = 1 MAX Q SIZE = 1 for TSProvider[#2]@952c78
2017-07-19 11:54:15,261 [DistributeCSTAEvent] INFO TsapiEventQueue - Getting event CSTAEvent[CSTAQueryDndConfEvent]@1051245 for TSProvider[#2]@952c78
2017-07-19 11:54:15,261 [DistributeCSTAEvent] INFO TSInvokeID - Handling INVOKE ID 12 for TSProvider[#2]@952c78
2017-07-19 11:54:15,261 [DistributeCSTAEvent] INFO TSInvokeID - DONE handling INVOKE ID 12 for TSProvider[#2]@952c78
2017-07-19 11:54:15,261 [localhost-startStop-1] INFO TsapiSession - Sent InvokeID 13 for TSProvider[#2]@952c78
2017-07-19 11:54:15,308 [GetEventThread] INFO TsapiSession - Received invokeID 13 for TSProvider[#2]@952c78
2017-07-19 11:54:15,308 [GetEventThread] INFO TsapiEventQueue - Putting event CSTAEvent[CSTAQueryMwiConfEvent]@15fc268. EVENT Q SIZE = 1 MAX Q SIZE = 1 for TSProvider[#2]@952c78
2017-07-19 11:54:15,308 [DistributeCSTAEvent] INFO TsapiEventQueue - Getting event CSTAEvent[CSTAQueryMwiConfEvent]@15fc268 for TSProvider[#2]@952c78
2017-07-19 11:54:15,308 [DistributeCSTAEvent] INFO TSInvokeID - Handling INVOKE ID 13 for TSProvider[#2]@952c78
2017-07-19 11:54:15,308 [DistributeCSTAEvent] INFO TSInvokeID - DONE handling INVOKE ID 13 for TSProvider[#2]@952c78
2017-07-19 11:54:15,308 [localhost-startStop-1] INFO TsapiSession - Sent InvokeID 14 for TSProvider[#2]@952c78
2017-07-19 11:54:15,371 [GetEventThread] INFO TsapiSession - Received invokeID 14 for TSProvider[#2]@952c78
2017-07-19 11:54:15,371 [GetEventThread] INFO TsapiEventQueue - Putting event CSTAEvent[CSTAQueryFwdConfEvent]@15ef52. EVENT Q SIZE = 1 MAX Q SIZE = 1 for TSProvider[#2]@952c78
2017-07-19 11:54:15,371 [DistributeCSTAEvent] INFO TsapiEventQueue - Getting event CSTAEvent[CSTAQueryFwdConfEvent]@15ef52 for TSProvider[#2]@952c78
2017-07-19 11:54:15,371 [DistributeCSTAEvent] INFO TSInvokeID - Handling INVOKE ID 14 for TSProvider[#2]@952c78
2017-07-19 11:54:15,371 [DistributeCSTAEvent] INFO TSInvokeID - DONE handling INVOKE ID 14 for TSProvider[#2]@952c78
2017-07-19 11:54:15,371 [localhost-startStop-1] INFO TsapiSession - Sent InvokeID 15 for TSProvider[#2]@952c78
2017-07-19 11:54:15,417 [GetEventThread] INFO TsapiSession - Received invokeID 15 for TSProvider[#2]@952c78
2017-07-19 11:54:15,433 [GetEventThread] INFO TSInvokeID - Handling INVOKE ID 15 for TSProvider[#2]@952c78
2017-07-19 11:54:15,433 [GetEventThread] INFO TSInvokeID - DONE handling INVOKE ID 15 for TSProvider[#2]@952c78
2017-07-19 11:54:15,433 [localhost-startStop-1] INFO TsapiSession - Sent InvokeID 16 for TSProvider[#2]@952c78
2017-07-19 11:54:15,464 [GetEventThread] INFO TsapiSession - Received invokeID 16 for TSProvider[#2]@952c78
2017-07-19 11:54:15,464 [GetEventThread] INFO TsapiEventQueue - Putting event CSTAEvent[CSTAUniversalFailureConfEvent]@14ab5b0. EVENT Q SIZE = 1 MAX Q SIZE = 1 for TSProvider[#2]@952c78
2017-07-19 11:54:15,464 [DistributeCSTAEvent] INFO TsapiEventQueue - Getting event CSTAEvent[CSTAUniversalFailureConfEvent]@14ab5b0 for TSProvider[#2]@952c78
2017-07-19 11:54:15,464 [DistributeCSTAEvent] INFO TSInvokeID - Handling INVOKE ID 16 for TSProvider[#2]@952c78
2017-07-19 11:54:15,464 [DistributeCSTAEvent] INFO TSInvokeID - DONE handling INVOKE ID 16 for TSProvider[#2]@952c78
2017-07-19 11:54:15,464 [localhost-startStop-1] INFO TsapiSession - Sent InvokeID 17 for TSProvider[#2]@952c78
2017-07-19 11:54:15,511 [GetEventThread] INFO TsapiSession - Received invokeID 17 for TSProvider[#2]@952c78
2017-07-19 11:54:15,511 [GetEventThread] INFO TsapiEventQueue - Putting event CSTAEvent[CSTASnapshotDeviceConfEvent]@2674e8. EVENT Q SIZE = 1 MAX Q SIZE = 1 for TSProvider[#2]@952c78
2017-07-19 11:54:15,511 [DistributeCSTAEvent] INFO TsapiEventQueue - Getting event CSTAEvent[CSTASnapshotDeviceConfEvent]@2674e8 for TSProvider[#2]@952c78
2017-07-19 11:54:15,511 [DistributeCSTAEvent] INFO LucentPrivateData - data PDU 72 not decoded
2017-07-19 11:54:15,511 [DistributeCSTAEvent] INFO TSInvokeID - Handling INVOKE ID 17 for TSProvider[#2]@952c78
2017-07-19 11:54:15,511 [DistributeCSTAEvent] INFO TSInvokeID - DONE handling INVOKE ID 17 for TSProvider[#2]@952c78
2017-07-19 11:54:15,511 [localhost-startStop-1] INFO LucentPrivateData - data PDU 72 not decoded
2017-07-19 11:54:15,511 [Thread-33] INFO TSDevice - Constructing device TSDevice[4501]@18eb98c with name 4501 for TSProvider[#2]@952c78
2017-07-19 11:54:15,511 [Thread-33] INFO TsapiSession - Sent InvokeID 18 for TSProvider[#2]@952c78
2017-07-19 11:54:15,511 [Thread-33] INFO TSDevice - getDeviceType() for TSDevice[4501]@18eb98c
2017-07-19 11:54:15,511 [Thread-33] INFO TSDevice - TSDevice[4501]@18eb98c waiting for initialization to complete
2017-07-19 11:54:15,558 [GetEventThread] INFO TsapiSession - Received invokeID 18 for TSProvider[#2]@952c78
2017-07-19 11:54:15,558 [GetEventThread] INFO TSInvokeID - Handling INVOKE ID 18 for TSProvider[#2]@952c78
2017-07-19 11:54:15,558 [GetEventThread] INFO TSDevice - Initialization complete for TSDevice TSDevice[4501]@18eb98c - making values available - for TSProvider[#2]@952c78
2017-07-19 11:54:15,558 [GetEventThread] INFO TSInvokeID - DONE handling INVOKE ID 18 for TSProvider[#2]@952c78
2017-07-19 11:54:15,558 [Thread-33] INFO TsapiSession - Sent InvokeID 19 for TSProvider[#2]@952c78
2017-07-19 11:54:15,620 [Thread-35] INFO TSDevice - Constructing device TSDevice[4502]@134b9f8 with name 4502 for TSProvider[#2]@952c78
2017-07-19 11:54:15,620 [GetEventThread] INFO TsapiSession - Received invokeID 19 for TSProvider[#2]@952c78
2017-07-19 11:54:15,620 [GetEventThread] INFO TSInvokeID - Handling INVOKE ID 19 for TSProvider[#2]@952c78
2017-07-19 11:54:15,620 [GetEventThread] INFO TSInvokeID - DONE handling INVOKE ID 19 for TSProvider[#2]@952c78
2017-07-19 11:54:15,620 [Thread-35] INFO TsapiSession - Sent InvokeID 20 for TSProvider[#2]@952c78
2017-07-19 11:54:15,620 [Thread-35] INFO TSDevice - getDeviceType() for TSDevice[4502]@134b9f8
2017-07-19 11:54:15,620 [Thread-35] INFO TSDevice - TSDevice[4502]@134b9f8 waiting for initialization to complete
2017-07-19 11:54:15,620 [Thread-33] INFO TsapiSession - Sent InvokeID 21 for TSProvider[#2]@952c78
2017-07-19 11:54:15,667 [GetEventThread] INFO TsapiSession - Received invokeID 20 for TSProvider[#2]@952c78
2017-07-19 11:54:15,667 [GetEventThread] INFO TSInvokeID - Handling INVOKE ID 20 for TSProvider[#2]@952c78
2017-07-19 11:54:15,667 [GetEventThread] INFO TSDevice - Initialization complete for TSDevice TSDevice[4502]@134b9f8 - making values available - for TSProvider[#2]@952c78
2017-07-19 11:54:15,667 [GetEventThread] INFO TSInvokeID - DONE handling INVOKE ID 20 for TSProvider[#2]@952c78
2017-07-19 11:54:15,667 [GetEventThread] INFO TsapiSession - Received invokeID 21 for TSProvider[#2]@952c78
2017-07-19 11:54:15,667 [GetEventThread] INFO TsapiEventQueue - Putting event CSTAEvent[CSTAQueryAgentStateConfEvent]@1355129. EVENT Q SIZE = 1 MAX Q SIZE = 1 for TSProvider[#2]@952c78
2017-07-19 11:54:15,667 [DistributeCSTAEvent] INFO TsapiEventQueue - Getting event CSTAEvent[CSTAQueryAgentStateConfEvent]@1355129 for TSProvider[#2]@952c78
2017-07-19 11:54:15,667 [DistributeCSTAEvent] INFO TSInvokeID - Handling INVOKE ID 21 for TSProvider[#2]@952c78
2017-07-19 11:54:15,667 [DistributeCSTAEvent] INFO TSInvokeID - DONE handling INVOKE ID 21 for TSProvider[#2]@952c78
2017-07-19 11:54:15,667 [Thread-35] INFO TsapiSession - Sent InvokeID 22 for TSProvider[#2]@952c78
2017-07-19 11:54:15,667 [Thread-33] INFO TsapiSession - Sent InvokeID 23 for TSProvider[#2]@952c78
2017-07-19 11:54:15,714 [GetEventThread] INFO TsapiSession - Received invokeID 22 for TSProvider[#2]@952c78
2017-07-19 11:54:15,714 [GetEventThread] INFO TSInvokeID - Handling INVOKE ID 22 for TSProvider[#2]@952c78
2017-07-19 11:54:15,714 [GetEventThread] INFO TSInvokeID - DONE handling INVOKE ID 22 for TSProvider[#2]@952c78
2017-07-19 11:54:15,714 [GetEventThread] INFO TsapiSession - Received invokeID 23 for TSProvider[#2]@952c78
2017-07-19 11:54:15,714 [GetEventThread] INFO TSInvokeID - Handling INVOKE ID 23 for TSProvider[#2]@952c78
2017-07-19 11:54:15,714 [GetEventThread] INFO TSInvokeID - DONE handling INVOKE ID 23 for TSProvider[#2]@952c78
2017-07-19 11:54:15,714 [Thread-33] INFO TsapiSession - Sent InvokeID 24 for TSProvider[#2]@952c78
2017-07-19 11:54:15,714 [Thread-35] INFO TsapiSession - Sent InvokeID 25 for TSProvider[#2]@952c78
2017-07-19 11:54:15,729 [Thread-41] INFO TSDevice - Constructing device TSDevice[4503]@117247a with name 4503 for TSProvider[#2]@952c78
2017-07-19 11:54:15,729 [Thread-41] INFO TsapiSession - Sent InvokeID 26 for TSProvider[#2]@952c78
2017-07-19 11:54:15,729 [Thread-41] INFO TSDevice - getDeviceType() for TSDevice[4503]@117247a
2017-07-19 11:54:15,729 [Thread-41] INFO TSDevice - TSDevice[4503]@117247a waiting for initialization to complete
2017-07-19 11:54:15,761 [GetEventThread] INFO TsapiSession - Received invokeID 24 for TSProvider[#2]@952c78
2017-07-19 11:54:15,761 [GetEventThread] INFO TsapiEventQueue - Putting event CSTAEvent[CSTAQueryDndConfEvent]@1c1c9f2. EVENT Q SIZE = 1 MAX Q SIZE = 1 for TSProvider[#2]@952c78
2017-07-19 11:54:15,761 [GetEventThread] INFO TsapiSession - Received invokeID 25 for TSProvider[#2]@952c78
2017-07-19 11:54:15,761 [GetEventThread] INFO TsapiEventQueue - Putting event CSTAEvent[CSTAQueryAgentStateConfEvent]@167ca20. EVENT Q SIZE = 2 MAX Q SIZE = 2 for TSProvider[#2]@952c78
2017-07-19 11:54:15,761 [GetEventThread] INFO TsapiSession - Received invokeID 26 for TSProvider[#2]@952c78
2017-07-19 11:54:15,761 [GetEventThread] INFO TSInvokeID - Handling INVOKE ID 26 for TSProvider[#2]@952c78
2017-07-19 11:54:15,761 [GetEventThread] INFO TSDevice - Initialization complete for TSDevice TSDevice[4503]@117247a - making values available - for TSProvider[#2]@952c78
2017-07-19 11:54:15,761 [GetEventThread] INFO TSInvokeID - DONE handling INVOKE ID 26 for TSProvider[#2]@952c78
2017-07-19 11:54:15,761 [Thread-41] INFO TsapiSession - Sent InvokeID 27 for TSProvider[#2]@952c78
2017-07-19 11:54:15,761 [DistributeCSTAEvent] INFO TsapiEventQueue - Getting event CSTAEvent[CSTAQueryDndConfEvent]@1c1c9f2 for TSProvider[#2]@952c78
2017-07-19 11:54:15,761 [DistributeCSTAEvent] INFO TSInvokeID - Handling INVOKE ID 24 for TSProvider[#2]@952c78
2017-07-19 11:54:15,761 [DistributeCSTAEvent] INFO TSInvokeID - DONE handling INVOKE ID 24 for TSProvider[#2]@952c78
2017-07-19 11:54:15,761 [DistributeCSTAEvent] INFO TsapiEventQueue - Getting event CSTAEvent[CSTAQueryAgentStateConfEvent]@167ca20 for TSProvider[#2]@952c78
2017-07-19 11:54:15,761 [DistributeCSTAEvent] INFO TSInvokeID - Handling INVOKE ID 25 for TSProvider[#2]@952c78
2017-07-19 11:54:15,761 [DistributeCSTAEvent] INFO TSInvokeID - DONE handling INVOKE ID 25 for TSProvider[#2]@952c78
2017-07-19 11:54:15,761 [Thread-33] INFO TsapiSession - Sent InvokeID 28 for TSProvider[#2]@952c78
2017-07-19 11:54:15,761 [Thread-35] INFO TsapiSession - Sent InvokeID 29 for TSProvider[#2]@952c78
2017-07-19 11:54:15,807 [GetEventThread] INFO TsapiSession - Received invokeID 27 for TSProvider[#2]@952c78
2017-07-19 11:54:15,823 [GetEventThread] INFO TSInvokeID - Handling INVOKE ID 27 for TSProvider[#2]@952c78
2017-07-19 11:54:15,823 [GetEventThread] INFO TSInvokeID - DONE handling INVOKE ID 27 for TSProvider[#2]@952c78
2017-07-19 11:54:15,823 [GetEventThread] INFO TsapiSession - Received invokeID 28 for TSProvider[#2]@952c78
2017-07-19 11:54:15,823 [GetEventThread] INFO TsapiEventQueue - Putting event CSTAEvent[CSTAQueryMwiConfEvent]@a16e50. EVENT Q SIZE = 1 MAX Q SIZE = 2 for TSProvider[#2]@952c78
2017-07-19 11:54:15,823 [GetEventThread] INFO TsapiSession - Received invokeID 29 for TSProvider[#2]@952c78
2017-07-19 11:54:15,823 [GetEventThread] INFO TSInvokeID - Handling INVOKE ID 29 for TSProvider[#2]@952c78
2017-07-19 11:54:15,823 [GetEventThread] INFO TSInvokeID - DONE handling INVOKE ID 29 for TSProvider[#2]@952c78
2017-07-19 11:54:15,823 [Thread-35] INFO TsapiSession - Sent InvokeID 30 for TSProvider[#2]@952c78
2017-07-19 11:54:15,823 [DistributeCSTAEvent] INFO TsapiEventQueue - Getting event CSTAEvent[CSTAQueryMwiConfEvent]@a16e50 for TSProvider[#2]@952c78
2017-07-19 11:54:15,823 [DistributeCSTAEvent] INFO TSInvokeID - Handling INVOKE ID 28 for TSProvider[#2]@952c78
2017-07-19 11:54:15,823 [DistributeCSTAEvent] INFO TSInvokeID - DONE handling INVOKE ID 28 for TSProvider[#2]@952c78
2017-07-19 11:54:15,823 [Thread-41] INFO TsapiSession - Sent InvokeID 31 for TSProvider[#2]@952c78
2017-07-19 11:54:15,823 [Thread-33] INFO TsapiSession - Sent InvokeID 32 for TSProvider[#2]@952c78
2017-07-19 11:54:15,839 [Thread-48] INFO TSDevice - Constructing device TSDevice[4504]@43e0e4 with name 4504 for TSProvider[#2]@952c78
2017-07-19 11:54:15,839 [Thread-48] INFO TsapiSession - Sent InvokeID 33 for TSProvider[#2]@952c78
2017-07-19 11:54:15,839 [Thread-48] INFO TSDevice - getDeviceType() for TSDevice[4504]@43e0e4
2017-07-19 11:54:15,839 [Thread-48] INFO TSDevice - TSDevice[4504]@43e0e4 waiting for initialization to complete
2017-07-19 11:54:15,870 [GetEventThread] INFO TsapiSession - Received invokeID 30 for TSProvider[#2]@952c78
2017-07-19 11:54:15,870 [GetEventThread] INFO TsapiEventQueue - Putting event CSTAEvent[CSTAQueryDndConfEvent]@1ced234. EVENT Q SIZE = 1 MAX Q SIZE = 2 for TSProvider[#2]@952c78
2017-07-19 11:54:15,870 [GetEventThread] INFO TsapiSession - Received invokeID 31 for TSProvider[#2]@952c78
2017-07-19 11:54:15,870 [GetEventThread] INFO TsapiEventQueue - Putting event CSTAEvent[CSTAQueryAgentStateConfEvent]@8506a6. EVENT Q SIZE = 2 MAX Q SIZE = 2 for TSProvider[#2]@952c78
2017-07-19 11:54:15,870 [GetEventThread] INFO TsapiSession - Received invokeID 32 for TSProvider[#2]@952c78
2017-07-19 11:54:15,870 [GetEventThread] INFO TsapiEventQueue - Putting event CSTAEvent[CSTAQueryFwdConfEvent]@100e1dc. EVENT Q SIZE = 3 MAX Q SIZE = 3 for TSProvider[#2]@952c78
2017-07-19 11:54:15,870 [GetEventThread] INFO TsapiSession - Received invokeID 33 for TSProvider[#2]@952c78
2017-07-19 11:54:15,870 [GetEventThread] INFO TSInvokeID - Handling INVOKE ID 33 for TSProvider[#2]@952c78
2017-07-19 11:54:15,870 [GetEventThread] INFO TSDevice - Initialization complete for TSDevice TSDevice[4504]@43e0e4 - making values available - for TSProvider[#2]@952c78
2017-07-19 11:54:15,870 [GetEventThread] INFO TSInvokeID - DONE handling INVOKE ID 33 for TSProvider[#2]@952c78
2017-07-19 11:54:15,870 [Thread-48] INFO TsapiSession - Sent InvokeID 34 for TSProvider[#2]@952c78
2017-07-19 11:54:15,870 [DistributeCSTAEvent] INFO TsapiEventQueue - Getting event CSTAEvent[CSTAQueryDndConfEvent]@1ced234 for TSProvider[#2]@952c78
2017-07-19 11:54:15,870 [DistributeCSTAEvent] INFO TSInvokeID - Handling INVOKE ID 30 for TSProvider[#2]@952c78
2017-07-19 11:54:15,870 [DistributeCSTAEvent] INFO TSInvokeID - DONE handling INVOKE ID 30 for TSProvider[#2]@952c78
2017-07-19 11:54:15,870 [DistributeCSTAEvent] INFO TsapiEventQueue - Getting event CSTAEvent[CSTAQueryAgentStateConfEvent]@8506a6 for TSProvider[#2]@952c78
2017-07-19 11:54:15,870 [DistributeCSTAEvent] INFO TSInvokeID - Handling INVOKE ID 31 for TSProvider[#2]@952c78
2017-07-19 11:54:15,870 [DistributeCSTAEvent] INFO TSInvokeID - DONE handling INVOKE ID 31 for TSProvider[#2]@952c78
2017-07-19 11:54:15,870 [DistributeCSTAEvent] INFO TsapiEventQueue - Getting event CSTAEvent[CSTAQueryFwdConfEvent]@100e1dc for TSProvider[#2]@952c78
2017-07-19 11:54:15,870 [DistributeCSTAEvent] INFO TSInvokeID - Handling INVOKE ID 32 for TSProvider[#2]@952c78
2017-07-19 11:54:15,870 [DistributeCSTAEvent] INFO TSInvokeID - DONE handling INVOKE ID 32 for TSProvider[#2]@952c78
2017-07-19 11:54:15,870 [Thread-35] INFO TsapiSession - Sent InvokeID 35 for TSProvider[#2]@952c78
2017-07-19 11:54:15,870 [Thread-41] INFO TsapiSession - Sent InvokeID 36 for TSProvider[#2]@952c78
2017-07-19 11:54:15,870 [Thread-33] INFO TsapiSession - Sent InvokeID 37 for TSProvider[#2]@952c78
2017-07-19 11:54:15,917 [GetEventThread] INFO TsapiSession - Received invokeID 34 for TSProvider[#2]@952c78
2017-07-19 11:54:15,917 [GetEventThread] INFO TSInvokeID - Handling INVOKE ID 34 for TSProvider[#2]@952c78
2017-07-19 11:54:15,917 [GetEventThread] INFO TSInvokeID - DONE handling INVOKE ID 34 for TSProvider[#2]@952c78
2017-07-19 11:54:15,917 [GetEventThread] INFO TsapiSession - Received invokeID 35 for TSProvider[#2]@952c78
2017-07-19 11:54:15,917 [GetEventThread] INFO TsapiEventQueue - Putting event CSTAEvent[CSTAQueryMwiConfEvent]@12d182. EVENT Q SIZE = 1 MAX Q SIZE = 3 for TSProvider[#2]@952c78
2017-07-19 11:54:15,917 [GetEventThread] INFO TsapiSession - Received invokeID 36 for TSProvider[#2]@952c78
2017-07-19 11:54:15,917 [GetEventThread] INFO TSInvokeID - Handling INVOKE ID 36 for TSProvider[#2]@952c78
2017-07-19 11:54:15,917 [GetEventThread] INFO TSInvokeID - DONE handling INVOKE ID 36 for TSProvider[#2]@952c78
2017-07-19 11:54:15,917 [GetEventThread] INFO TsapiSession - Received invokeID 37 for TSProvider[#2]@952c78
2017-07-19 11:54:15,917 [GetEventThread] INFO TSInvokeID - Handling INVOKE ID 37 for TSProvider[#2]@952c78
2017-07-19 11:54:15,917 [GetEventThread] INFO TSInvokeID - DONE handling INVOKE ID 37 for TSProvider[#2]@952c78
2017-07-19 11:54:15,917 [Thread-48] INFO TsapiSession - Sent InvokeID 38 for TSProvider[#2]@952c78
2017-07-19 11:54:15,917 [DistributeCSTAEvent] INFO TsapiEventQueue - Getting event CSTAEvent[CSTAQueryMwiConfEvent]@12d182 for TSProvider[#2]@952c78
2017-07-19 11:54:15,917 [DistributeCSTAEvent] INFO TSInvokeID - Handling INVOKE ID 35 for TSProvider[#2]@952c78
2017-07-19 11:54:15,917 [DistributeCSTAEvent] INFO TSInvokeID - DONE handling INVOKE ID 35 for TSProvider[#2]@952c78
2017-07-19 11:54:15,917 [Thread-41] INFO TsapiSession - Sent InvokeID 39 for TSProvider[#2]@952c78
2017-07-19 11:54:15,917 [Thread-33] INFO TsapiSession - Sent InvokeID 40 for TSProvider[#2]@952c78
2017-07-19 11:54:15,917 [Thread-35] INFO TsapiSession - Sent InvokeID 41 for TSProvider[#2]@952c78
2017-07-19 11:54:15,948 [Thread-57] INFO TSDevice - Constructing device TSDevice[4505]@14c9887 with name 4505 for TSProvider[#2]@952c78
2017-07-19 11:54:15,948 [Thread-57] INFO TsapiSession - Sent InvokeID 42 for TSProvider[#2]@952c78
2017-07-19 11:54:15,948 [Thread-57] INFO TSDevice - getDeviceType() for TSDevice[4505]@14c9887
2017-07-19 11:54:15,948 [Thread-57] INFO TSDevice - TSDevice[4505]@14c9887 waiting for initialization to complete
2017-07-19 11:54:15,963 [GetEventThread] INFO TsapiSession - Received invokeID 38 for TSProvider[#2]@952c78
2017-07-19 11:54:15,963 [GetEventThread] INFO TsapiEventQueue - Putting event CSTAEvent[CSTAQueryAgentStateConfEvent]@122e906. EVENT Q SIZE = 1 MAX Q SIZE = 3 for TSProvider[#2]@952c78
2017-07-19 11:54:15,963 [GetEventThread] INFO TsapiSession - Received invokeID 39 for TSProvider[#2]@952c78
2017-07-19 11:54:15,963 [GetEventThread] INFO TsapiEventQueue - Putting event CSTAEvent[CSTAQueryDndConfEvent]@16677b2. EVENT Q SIZE = 2 MAX Q SIZE = 3 for TSProvider[#2]@952c78
2017-07-19 11:54:15,963 [GetEventThread] INFO TsapiSession - Received invokeID 40 for TSProvider[#2]@952c78
2017-07-19 11:54:15,963 [GetEventThread] INFO TsapiEventQueue - Putting event CSTAEvent[CSTAUniversalFailureConfEvent]@1007ec3. EVENT Q SIZE = 3 MAX Q SIZE = 3 for TSProvider[#2]@952c78
2017-07-19 11:54:15,963 [GetEventThread] INFO TsapiSession - Received invokeID 41 for TSProvider[#2]@952c78
2017-07-19 11:54:15,963 [GetEventThread] INFO TsapiEventQueue - Putting event CSTAEvent[CSTAQueryFwdConfEvent]@1a62a20. EVENT Q SIZE = 4 MAX Q SIZE = 4 for TSProvider[#2]@952c78
2017-07-19 11:54:15,963 [GetEventThread] INFO TsapiSession - Received invokeID 42 for TSProvider[#2]@952c78
2017-07-19 11:54:15,963 [GetEventThread] INFO TSInvokeID - Handling INVOKE ID 42 for TSProvider[#2]@952c78
2017-07-19 11:54:15,963 [GetEventThread] INFO TSDevice - Initialization complete for TSDevice TSDevice[4505]@14c9887 - making values available - for TSProvider[#2]@952c78
2017-07-19 11:54:15,963 [GetEventThread] INFO TSInvokeID - DONE handling INVOKE ID 42 for TSProvider[#2]@952c78
2017-07-19 11:54:15,963 [Thread-57] INFO TsapiSession - Sent InvokeID 43 for TSProvider[#2]@952c78
2017-07-19 11:54:15,963 [DistributeCSTAEvent] INFO TsapiEventQueue - Getting event CSTAEvent[CSTAQueryAgentStateConfEvent]@122e906 for TSProvider[#2]@952c78
2017-07-19 11:54:15,963 [DistributeCSTAEvent] INFO TSInvokeID - Handling INVOKE ID 38 for TSProvider[#2]@952c78
2017-07-19 11:54:15,963 [DistributeCSTAEvent] INFO TSInvokeID - DONE handling INVOKE ID 38 for TSProvider[#2]@952c78
2017-07-19 11:54:15,963 [DistributeCSTAEvent] INFO TsapiEventQueue - Getting event CSTAEvent[CSTAQueryDndConfEvent]@16677b2 for TSProvider[#2]@952c78
2017-07-19 11:54:15,963 [DistributeCSTAEvent] INFO TSInvokeID - Handling INVOKE ID 39 for TSProvider[#2]@952c78
2017-07-19 11:54:15,963 [DistributeCSTAEvent] INFO TSInvokeID - DONE handling INVOKE ID 39 for TSProvider[#2]@952c78
2017-07-19 11:54:15,963 [DistributeCSTAEvent] INFO TsapiEventQueue - Getting event CSTAEvent[CSTAUniversalFailureConfEvent]@1007ec3 for TSProvider[#2]@952c78
2017-07-19 11:54:15,963 [DistributeCSTAEvent] INFO TSInvokeID - Handling INVOKE ID 40 for TSProvider[#2]@952c78
2017-07-19 11:54:15,963 [DistributeCSTAEvent] INFO TSInvokeID - DONE handling INVOKE ID 40 for TSProvider[#2]@952c78
2017-07-19 11:54:15,963 [DistributeCSTAEvent] INFO TsapiEventQueue - Getting event CSTAEvent[CSTAQueryFwdConfEvent]@1a62a20 for TSProvider[#2]@952c78
2017-07-19 11:54:15,963 [DistributeCSTAEvent] INFO TSInvokeID - Handling INVOKE ID 41 for TSProvider[#2]@952c78
2017-07-19 11:54:15,963 [DistributeCSTAEvent] INFO TSInvokeID - DONE handling INVOKE ID 41 for TSProvider[#2]@952c78
2017-07-19 11:54:15,963 [Thread-48] INFO TsapiSession - Sent InvokeID 44 for TSProvider[#2]@952c78
2017-07-19 11:54:15,979 [Thread-41] INFO TsapiSession - Sent InvokeID 45 for TSProvider[#2]@952c78
2017-07-19 11:54:15,979 [Thread-33] INFO TsapiSession - Sent InvokeID 46 for TSProvider[#2]@952c78
2017-07-19 11:54:15,979 [Thread-35] INFO TsapiSession - Sent InvokeID 47 for TSProvider[#2]@952c78
2017-07-19 11:54:16,010 [GetEventThread] INFO TsapiSession - Received invokeID 43 for TSProvider[#2]@952c78
2017-07-19 11:54:16,026 [GetEventThread] INFO TSInvokeID - Handling INVOKE ID 43 for TSProvider[#2]@952c78
2017-07-19 11:54:16,026 [GetEventThread] INFO TSInvokeID - DONE handling INVOKE ID 43 for TSProvider[#2]@952c78
2017-07-19 11:54:16,026 [GetEventThread] INFO TsapiSession - Received invokeID 44 for TSProvider[#2]@952c78
2017-07-19 11:54:16,026 [GetEventThread] INFO TSInvokeID - Handling INVOKE ID 44 for TSProvider[#2]@952c78
2017-07-19 11:54:16,026 [GetEventThread] INFO TSInvokeID - DONE handling INVOKE ID 44 for TSProvider[#2]@952c78
2017-07-19 11:54:16,026 [GetEventThread] INFO TsapiSession - Received invokeID 45 for TSProvider[#2]@952c78
2017-07-19 11:54:16,026 [GetEventThread] INFO TsapiEventQueue - Putting event CSTAEvent[CSTAQueryMwiConfEvent]@11a954b. EVENT Q SIZE = 1 MAX Q SIZE = 4 for TSProvider[#2]@952c78
2017-07-19 11:54:16,026 [GetEventThread] INFO TsapiSession - Received invokeID 46 for TSProvider[#2]@952c78
2017-07-19 11:54:16,026 [GetEventThread] INFO TsapiEventQueue - Putting event CSTAEvent[CSTASnapshotDeviceConfEvent]@1c7bf7d. EVENT Q SIZE = 2 MAX Q SIZE = 4 for TSProvider[#2]@952c78
2017-07-19 11:54:16,026 [GetEventThread] INFO TsapiSession - Received invokeID 47 for TSProvider[#2]@952c78
2017-07-19 11:54:16,026 [GetEventThread] INFO TSInvokeID - Handling INVOKE ID 47 for TSProvider[#2]@952c78
2017-07-19 11:54:16,026 [GetEventThread] INFO TSInvokeID - DONE handling INVOKE ID 47 for TSProvider[#2]@952c78
2017-07-19 11:54:16,026 [Thread-57] INFO TsapiSession - Sent InvokeID 48 for TSProvider[#2]@952c78
2017-07-19 11:54:16,026 [Thread-48] INFO TsapiSession - Sent InvokeID 49 for TSProvider[#2]@952c78
2017-07-19 11:54:16,026 [DistributeCSTAEvent] INFO TsapiEventQueue - Getting event CSTAEvent[CSTAQueryMwiConfEvent]@11a954b for TSProvider[#2]@952c78
2017-07-19 11:54:16,026 [DistributeCSTAEvent] INFO TSInvokeID - Handling INVOKE ID 45 for TSProvider[#2]@952c78
2017-07-19 11:54:16,026 [DistributeCSTAEvent] INFO TSInvokeID - DONE handling INVOKE ID 45 for TSProvider[#2]@952c78
2017-07-19 11:54:16,026 [DistributeCSTAEvent] INFO TsapiEventQueue - Getting event CSTAEvent[CSTASnapshotDeviceConfEvent]@1c7bf7d for TSProvider[#2]@952c78
2017-07-19 11:54:16,026 [DistributeCSTAEvent] INFO LucentPrivateData - data PDU 72 not decoded
2017-07-19 11:54:16,026 [DistributeCSTAEvent] INFO TSInvokeID - Handling INVOKE ID 46 for TSProvider[#2]@952c78
2017-07-19 11:54:16,026 [DistributeCSTAEvent] INFO TSInvokeID - DONE handling INVOKE ID 46 for TSProvider[#2]@952c78
2017-07-19 11:54:16,026 [Thread-35] INFO TsapiSession - Sent InvokeID 50 for TSProvider[#2]@952c78
2017-07-19 11:54:16,026 [Thread-41] INFO TsapiSession - Sent InvokeID 51 for TSProvider[#2]@952c78
2017-07-19 11:54:16,026 [Thread-33] INFO LucentPrivateData - data PDU 72 not decoded
2017-07-19 11:54:16,057 [Thread-68] INFO TSDevice - Constructing device TSDevice[4506]@1a63c2 with name 4506 for TSProvider[#2]@952c78
2017-07-19 11:54:16,057 [Thread-68] INFO TsapiSession - Sent InvokeID 52 for TSProvider[#2]@952c78
2017-07-19 11:54:16,057 [Thread-68] INFO TSDevice - getDeviceType() for TSDevice[4506]@1a63c2
2017-07-19 11:54:16,057 [Thread-68] INFO TSDevice - TSDevice[4506]@1a63c2 waiting for initialization to complete
2017-07-19 11:54:16,073 [GetEventThread] INFO TsapiSession - Received invokeID 48 for TSProvider[#2]@952c78
2017-07-19 11:54:16,073 [GetEventThread] INFO TsapiEventQueue - Putting event CSTAEvent[CSTAQueryAgentStateConfEvent]@16f3960. EVENT Q SIZE = 1 MAX Q SIZE = 4 for TSProvider[#2]@952c78
2017-07-19 11:54:16,073 [GetEventThread] INFO TsapiSession - Received invokeID 49 for TSProvider[#2]@952c78
2017-07-19 11:54:16,073 [GetEventThread] INFO TsapiEventQueue - Putting event CSTAEvent[CSTAQueryDndConfEvent]@1ccf907. EVENT Q SIZE = 2 MAX Q SIZE = 4 for TSProvider[#2]@952c78
2017-07-19 11:54:16,073 [GetEventThread] INFO TsapiSession - Received invokeID 50 for TSProvider[#2]@952c78
2017-07-19 11:54:16,073 [GetEventThread] INFO TsapiEventQueue - Putting event CSTAEvent[CSTAUniversalFailureConfEvent]@1b9378. EVENT Q SIZE = 3 MAX Q SIZE = 4 for TSProvider[#2]@952c78
2017-07-19 11:54:16,073 [GetEventThread] INFO TsapiSession - Received invokeID 51 for TSProvider[#2]@952c78
2017-07-19 11:54:16,073 [GetEventThread] INFO TsapiEventQueue - Putting event CSTAEvent[CSTAQueryFwdConfEvent]@afe351. EVENT Q SIZE = 4 MAX Q SIZE = 4 for TSProvider[#2]@952c78
2017-07-19 11:54:16,073 [GetEventThread] INFO TsapiSession - Received invokeID 52 for TSProvider[#2]@952c78
2017-07-19 11:54:16,073 [GetEventThread] INFO TSInvokeID - Handling INVOKE ID 52 for TSProvider[#2]@952c78
2017-07-19 11:54:16,073 [GetEventThread] INFO TSDevice - Initialization complete for TSDevice TSDevice[4506]@1a63c2 - making values available - for TSProvider[#2]@952c78
2017-07-19 11:54:16,073 [GetEventThread] INFO TSInvokeID - DONE handling INVOKE ID 52 for TSProvider[#2]@952c78
2017-07-19 11:54:16,073 [Thread-68] INFO TsapiSession - Sent InvokeID 53 for TSProvider[#2]@952c78
2017-07-19 11:54:16,073 [DistributeCSTAEvent] INFO TsapiEventQueue - Getting event CSTAEvent[CSTAQueryAgentStateConfEvent]@16f3960 for TSProvider[#2]@952c78
2017-07-19 11:54:16,073 [DistributeCSTAEvent] INFO TSInvokeID - Handling INVOKE ID 48 for TSProvider[#2]@952c78
2017-07-19 11:54:16,073 [DistributeCSTAEvent] INFO TSInvokeID - DONE handling INVOKE ID 48 for TSProvider[#2]@952c78
2017-07-19 11:54:16,073 [DistributeCSTAEvent] INFO TsapiEventQueue - Getting event CSTAEvent[CSTAQueryDndConfEvent]@1ccf907 for TSProvider[#2]@952c78
2017-07-19 11:54:16,073 [DistributeCSTAEvent] INFO TSInvokeID - Handling INVOKE ID 49 for TSProvider[#2]@952c78
2017-07-19 11:54:16,073 [DistributeCSTAEvent] INFO TSInvokeID - DONE handling INVOKE ID 49 for TSProvider[#2]@952c78
2017-07-19 11:54:16,073 [DistributeCSTAEvent] INFO TsapiEventQueue - Getting event CSTAEvent[CSTAUniversalFailureConfEvent]@1b9378 for TSProvider[#2]@952c78
2017-07-19 11:54:16,073 [DistributeCSTAEvent] INFO TSInvokeID - Handling INVOKE ID 50 for TSProvider[#2]@952c78
2017-07-19 11:54:16,073 [DistributeCSTAEvent] INFO TSInvokeID - DONE handling INVOKE ID 50 for TSProvider[#2]@952c78
2017-07-19 11:54:16,073 [DistributeCSTAEvent] INFO TsapiEventQueue - Getting event CSTAEvent[CSTAQueryFwdConfEvent]@afe351 for TSProvider[#2]@952c78
2017-07-19 11:54:16,073 [DistributeCSTAEvent] INFO TSInvokeID - Handling INVOKE ID 51 for TSProvider[#2]@952c78
2017-07-19 11:54:16,073 [DistributeCSTAEvent] INFO TSInvokeID - DONE handling INVOKE ID 51 for TSProvider[#2]@952c78
2017-07-19 11:54:16,073 [Thread-57] INFO TsapiSession - Sent InvokeID 54 for TSProvider[#2]@952c78
2017-07-19 11:54:16,073 [Thread-48] INFO TsapiSession - Sent InvokeID 55 for TSProvider[#2]@952c78
2017-07-19 11:54:16,073 [Thread-35] INFO TsapiSession - Sent InvokeID 56 for TSProvider[#2]@952c78
2017-07-19 11:54:16,073 [Thread-41] INFO TsapiSession - Sent InvokeID 57 for TSProvider[#2]@952c78
2017-07-19 11:54:16,119 [GetEventThread] INFO TsapiSession - Received invokeID 53 for TSProvider[#2]@952c78
2017-07-19 11:54:16,119 [GetEventThread] INFO TSInvokeID - Handling INVOKE ID 53 for TSProvider[#2]@952c78
2017-07-19 11:54:16,119 [GetEventThread] INFO TSInvokeID - DONE handling INVOKE ID 53 for TSProvider[#2]@952c78
2017-07-19 11:54:16,119 [GetEventThread] INFO TsapiSession - Received invokeID 54 for TSProvider[#2]@952c78
2017-07-19 11:54:16,119 [GetEventThread] INFO TSInvokeID - Handling INVOKE ID 54 for TSProvider[#2]@952c78
2017-07-19 11:54:16,119 [GetEventThread] INFO TSInvokeID - DONE handling INVOKE ID 54 for TSProvider[#2]@952c78
2017-07-19 11:54:16,119 [GetEventThread] INFO TsapiSession - Received invokeID 55 for TSProvider[#2]@952c78
2017-07-19 11:54:16,119 [GetEventThread] INFO TsapiEventQueue - Putting event CSTAEvent[CSTAQueryMwiConfEvent]@99741d. EVENT Q SIZE = 1 MAX Q SIZE = 4 for TSProvider[#2]@952c78
2017-07-19 11:54:16,119 [GetEventThread] INFO TsapiSession - Received invokeID 56 for TSProvider[#2]@952c78
2017-07-19 11:54:16,119 [GetEventThread] INFO TsapiEventQueue - Putting event CSTAEvent[CSTASnapshotDeviceConfEvent]@45a988. EVENT Q SIZE = 2 MAX Q SIZE = 4 for TSProvider[#2]@952c78
2017-07-19 11:54:16,119 [GetEventThread] INFO TsapiSession - Received invokeID 57 for TSProvider[#2]@952c78
2017-07-19 11:54:16,119 [GetEventThread] INFO TSInvokeID - Handling INVOKE ID 57 for TSProvider[#2]@952c78
2017-07-19 11:54:16,119 [GetEventThread] INFO TSInvokeID - DONE handling INVOKE ID 57 for TSProvider[#2]@952c78
2017-07-19 11:54:16,119 [Thread-68] INFO TsapiSession - Sent InvokeID 58 for TSProvider[#2]@952c78
2017-07-19 11:54:16,119 [Thread-57] INFO TsapiSession - Sent InvokeID 59 for TSProvider[#2]@952c78
2017-07-19 11:54:16,119 [DistributeCSTAEvent] INFO TsapiEventQueue - Getting event CSTAEvent[CSTAQueryMwiConfEvent]@99741d for TSProvider[#2]@952c78
2017-07-19 11:54:16,119 [DistributeCSTAEvent] INFO TSInvokeID - Handling INVOKE ID 55 for TSProvider[#2]@952c78
2017-07-19 11:54:16,119 [DistributeCSTAEvent] INFO TSInvokeID - DONE handling INVOKE ID 55 for TSProvider[#2]@952c78
2017-07-19 11:54:16,119 [DistributeCSTAEvent] INFO TsapiEventQueue - Getting event CSTAEvent[CSTASnapshotDeviceConfEvent]@45a988 for TSProvider[#2]@952c78
2017-07-19 11:54:16,119 [DistributeCSTAEvent] INFO LucentPrivateData - data PDU 72 not decoded
2017-07-19 11:54:16,119 [DistributeCSTAEvent] INFO TSInvokeID - Handling INVOKE ID 56 for TSProvider[#2]@952c78
2017-07-19 11:54:16,119 [DistributeCSTAEvent] INFO TSInvokeID - DONE handling INVOKE ID 56 for TSProvider[#2]@952c78
2017-07-19 11:54:16,119 [Thread-41] INFO TsapiSession - Sent InvokeID 60 for TSProvider[#2]@952c78
2017-07-19 11:54:16,119 [Thread-48] INFO TsapiSession - Sent InvokeID 61 for TSProvider[#2]@952c78
2017-07-19 11:54:16,119 [Thread-35] INFO LucentPrivateData - data PDU 72 not decoded
2017-07-19 11:54:16,166 [Thread-79] INFO TSDevice - Constructing device TSDevice[4507]@a1db61 with name 4507 for TSProvider[#2]@952c78
2017-07-19 11:54:16,166 [Thread-79] INFO TsapiSession - Sent InvokeID 62 for TSProvider[#2]@952c78
2017-07-19 11:54:16,166 [Thread-79] INFO TSDevice - getDeviceType() for TSDevice[4507]@a1db61
2017-07-19 11:54:16,166 [Thread-79] INFO TSDevice - TSDevice[4507]@a1db61 waiting for initialization to complete
2017-07-19 11:54:16,166 [GetEventThread] INFO TsapiSession - Received invokeID 58 for TSProvider[#2]@952c78
2017-07-19 11:54:16,166 [GetEventThread] INFO TsapiEventQueue - Putting event CSTAEvent[CSTAQueryAgentStateConfEvent]@c179eb. EVENT Q SIZE = 1 MAX Q SIZE = 4 for TSProvider[#2]@952c78
2017-07-19 11:54:16,166 [GetEventThread] INFO TsapiSession - Received invokeID 59 for TSProvider[#2]@952c78
2017-07-19 11:54:16,166 [GetEventThread] INFO TsapiEventQueue - Putting event CSTAEvent[CSTAQueryDndConfEvent]@15ba409. EVENT Q SIZE = 2 MAX Q SIZE = 4 for TSProvider[#2]@952c78
2017-07-19 11:54:16,166 [GetEventThread] INFO TsapiSession - Received invokeID 60 for TSProvider[#2]@952c78
2017-07-19 11:54:16,166 [GetEventThread] INFO TsapiEventQueue - Putting event CSTAEvent[CSTAUniversalFailureConfEvent]@6b07a3. EVENT Q SIZE = 3 MAX Q SIZE = 4 for TSProvider[#2]@952c78
2017-07-19 11:54:16,166 [GetEventThread] INFO TsapiSession - Received invokeID 61 for TSProvider[#2]@952c78
2017-07-19 11:54:16,166 [GetEventThread] INFO TsapiEventQueue - Putting event CSTAEvent[CSTAQueryFwdConfEvent]@155e0cf. EVENT Q SIZE = 4 MAX Q SIZE = 4 for TSProvider[#2]@952c78
2017-07-19 11:54:16,166 [GetEventThread] INFO TsapiSession - Received invokeID 62 for TSProvider[#2]@952c78
2017-07-19 11:54:16,166 [GetEventThread] INFO TSInvokeID - Handling INVOKE ID 62 for TSProvider[#2]@952c78
2017-07-19 11:54:16,166 [GetEventThread] INFO TSDevice - Initialization complete for TSDevice TSDevice[4507]@a1db61 - making values available - for TSProvider[#2]@952c78
2017-07-19 11:54:16,166 [GetEventThread] INFO TSInvokeID - DONE handling INVOKE ID 62 for TSProvider[#2]@952c78
2017-07-19 11:54:16,166 [Thread-79] INFO TsapiSession - Sent InvokeID 63 for TSProvider[#2]@952c78
2017-07-19 11:54:16,166 [DistributeCSTAEvent] INFO TsapiEventQueue - Getting event CSTAEvent[CSTAQueryAgentStateConfEvent]@c179eb for TSProvider[#2]@952c78
2017-07-19 11:54:16,166 [DistributeCSTAEvent] INFO TSInvokeID - Handling INVOKE ID 58 for TSProvider[#2]@952c78
2017-07-19 11:54:16,166 [DistributeCSTAEvent] INFO TSInvokeID - DONE handling INVOKE ID 58 for TSProvider[#2]@952c78
2017-07-19 11:54:16,166 [DistributeCSTAEvent] INFO TsapiEventQueue - Getting event CSTAEvent[CSTAQueryDndConfEvent]@15ba409 for TSProvider[#2]@952c78
2017-07-19 11:54:16,166 [DistributeCSTAEvent] INFO TSInvokeID - Handling INVOKE ID 59 for TSProvider[#2]@952c78
2017-07-19 11:54:16,166 [DistributeCSTAEvent] INFO TSInvokeID - DONE handling INVOKE ID 59 for TSProvider[#2]@952c78
2017-07-19 11:54:16,166 [DistributeCSTAEvent] INFO TsapiEventQueue - Getting event CSTAEvent[CSTAUniversalFailureConfEvent]@6b07a3 for TSProvider[#2]@952c78
2017-07-19 11:54:16,166 [DistributeCSTAEvent] INFO TSInvokeID - Handling INVOKE ID 60 for TSProvider[#2]@952c78
2017-07-19 11:54:16,166 [DistributeCSTAEvent] INFO TSInvokeID - DONE handling INVOKE ID 60 for TSProvider[#2]@952c78
2017-07-19 11:54:16,166 [DistributeCSTAEvent] INFO TsapiEventQueue - Getting event CSTAEvent[CSTAQueryFwdConfEvent]@155e0cf for TSProvider[#2]@952c78
2017-07-19 11:54:16,166 [DistributeCSTAEvent] INFO TSInvokeID - Handling INVOKE ID 61 for TSProvider[#2]@952c78
2017-07-19 11:54:16,166 [DistributeCSTAEvent] INFO TSInvokeID - DONE handling INVOKE ID 61 for TSProvider[#2]@952c78
2017-07-19 11:54:16,166 [Thread-68] INFO TsapiSession - Sent InvokeID 64 for TSProvider[#2]@952c78
2017-07-19 11:54:16,166 [Thread-57] INFO TsapiSession - Sent InvokeID 65 for TSProvider[#2]@952c78
2017-07-19 11:54:16,166 [Thread-41] INFO TsapiSession - Sent InvokeID 66 for TSProvider[#2]@952c78
2017-07-19 11:54:16,166 [Thread-48] INFO TsapiSession - Sent InvokeID 67 for TSProvider[#2]@952c78
2017-07-19 11:54:16,229 [GetEventThread] INFO TsapiSession - Received invokeID 63 for TSProvider[#2]@952c78
2017-07-19 11:54:16,229 [GetEventThread] INFO TSInvokeID - Handling INVOKE ID 63 for TSProvider[#2]@952c78
2017-07-19 11:54:16,229 [GetEventThread] INFO TSInvokeID - DONE handling INVOKE ID 63 for TSProvider[#2]@952c78
2017-07-19 11:54:16,229 [GetEventThread] INFO TsapiSession - Received invokeID 64 for TSProvider[#2]@952c78
2017-07-19 11:54:16,229 [GetEventThread] INFO TSInvokeID - Handling INVOKE ID 64 for TSProvider[#2]@952c78
2

I am looking for the trace.log in the aesconnector directory instead.

Hi ,

Please find attached trace log as well aes connector war file.

Thanks

So in the app log you posted earlier it shows one session trying to make a outbound call and the aesconnector didn't return before the session was over.

19/07/2017 16:28:50:608 DEBUG - BF9E70003D8F316DE18104D1C23283B3:/iAssistOutboundDialog_H323_VXML_2.2.1.8.0 : CTICommand.execute: request to manager is http://172.16.3.138:8080/aesconnector/Dial?callee%3D98123694237%26uui%3D2331%26uuiAsAscii%3Dtrue%26ringMax%3D6%26extension%3D4500%26holdAddress%3D2331&k=BfXTOrU3QhO4qO7zNQcCgunyc5jT4bNvwbk4RMtGaIk%3D
19/07/2017 16:28:50:608 DEBUG - BF9E70003D8F316DE18104D1C23283B3:/iAssistOutboundDialog_H323_VXML_2.2.1.8.0 : CTICommand.execute: setting session cookie to BF9E70003D8F316DE18104D1C23283B3:/iAssistOutboundDialog_H323_VXML_2.2.1.8.0
19/07/2017 16:29:30:622 INFO - BF9E70003D8F316DE18104D1C23283B3:/iAssistOutboundDialog_H323_VXML_2.2.1.8.0 : HTTP Session lost removing SCESession BF9E70003D8F316DE18104D1C23283B3


What I found in the aesconnector log is the aes connector did not seem to be very active. Something it idles for seconds between 16:28:50:764 and 19/07/2017 16:29:44:865 which is the duration of the problem showing in the app log. I am not sure what is going on. It could be something related to how you do the test. Do you have a few more calls happening consistently? I only see this one call here.


19/07/2017 16:28:50:764 DEBUG - CTICallObserver.callChangedEvent:4500: Found connections object, but not 2 active connections. May be using FastConnect
19/07/2017 16:28:58:439 DEBUG - ProviderMonitor: Checking:Acqueon for availability
19/07/2017 16:28:59:562 DEBUG - CTIConnectorManager.RetryConfigObservers:4510 was unable to come up upon startup, reget observer
19/07/2017 16:28:59:781 ERROR - CTICallObserver.CTICallObserver: failed to add an observer on extension: 4510 error is failure to monitor device
19/07/2017 16:29:05:709 DEBUG - CTICallOperation.makeCall: Exception com.avaya.jtapi.tsapi.TsapiPlatformException: Could not meet post-conditions of connect()
19/07/2017 16:29:05:709 DEBUG - error type is 4 code is 0
19/07/2017 16:29:05:709 DEBUG - CTICallOperation.makeCall 4500: Waiting on mutex
19/07/2017 16:29:07:674 DEBUG - ProviderMonitor: Checking:Acqueon for availability
19/07/2017 16:29:09:063 DEBUG - CTIConnectorManager.RetryConfigObservers:4510 was unable to come up upon startup, reget observer
19/07/2017 16:29:09:328 ERROR - CTICallObserver.CTICallObserver: failed to add an observer on extension: 4510 error is failure to monitor device
19/07/2017 16:29:17:175 DEBUG - ProviderMonitor: Checking:Acqueon for availability
19/07/2017 16:29:18:298 DEBUG - CTIConnectorManager.RetryConfigObservers:4510 was unable to come up upon startup, reget observer
19/07/2017 16:29:18:501 ERROR - CTICallObserver.CTICallObserver: failed to add an observer on extension: 4510 error is failure to monitor device
19/07/2017 16:29:26:410 DEBUG - ProviderMonitor: Checking:Acqueon for availability
19/07/2017 16:29:27:518 DEBUG - CTIConnectorManager.RetryConfigObservers:4510 was unable to come up upon startup, reget observer
19/07/2017 16:29:27:689 ERROR - CTICallObserver.CTICallObserver: failed to add an observer on extension: 4510 error is failure to monitor device
19/07/2017 16:29:35:630 DEBUG - ProviderMonitor: Checking:Acqueon for availability
19/07/2017 16:29:36:753 DEBUG - CTIConnectorManager.RetryConfigObservers:4510 was unable to come up upon startup, reget observer
19/07/2017 16:29:36:909 ERROR - CTICallObserver.CTICallObserver: failed to add an observer on extension: 4510 error is failure to monitor device
19/07/2017 16:29:38:796 DEBUG - CTICallObserver.callChangedEvent: Number of events on extension 4500 is 3
19/07/2017 16:29:38:796 DEBUG - CTICallObserver.callChangedEvent 4500: Event: 0 is 106 for call 2337 Provider:Acqueon
19/07/2017 16:29:38:796 DEBUG - CTICallObserver.callChangedEvent4500: got Connection Created Event for id:2337
19/07/2017 16:29:38:796 DEBUG - CTICallObserver.callChangedEvent4500: Saving most recent call created:2337
19/07/2017 16:29:38:796 DEBUG - CTICallObserver.addCall 4500: call id is 2337 is already added, returning call data
19/07/2017 16:29:38:796 DEBUG - CTICallObserver.notifyApplicationObserver: Notifying 4500 about call event
19/07/2017 16:29:38:796 DEBUG - CTICallObserver.callChangedEvent 4500: Event: 1 is 108 for call 2337 Provider:Acqueon
19/07/2017 16:29:38:796 DEBUG - CTICallObserver.callChangedEvent:4500: got Connection Failed Event
19/07/2017 16:29:38:796 DEBUG - CTICallObserver.callChangedEvent:4500: cause:103
19/07/2017 16:29:38:796 DEBUG - CTICallObserver.callChangedEvent:4500: Call id 2337 is unreachable
19/07/2017 16:29:38:796 DEBUG - CTICallObserver.updateCallState 4500: setting call:2337 to state:unreachable
19/07/2017 16:29:38:796 DEBUG - CTICallObserver.updateCallState 4500: setting cached call:2337 to state:unreachable
19/07/2017 16:29:38:796 DEBUG - CTICallObserver.notifyApplicationObserver: Notifying 4500 about call event
19/07/2017 16:29:38:796 DEBUG - CTICallOperation.applicationCallEvent 4500: got a call failure
19/07/2017 16:29:38:796 DEBUG - Dial.StopCallTimer: Could find no timer to cancel for callid:2337
19/07/2017 16:29:38:796 DEBUG - getObserversFromCallId: gathering observers... done waiting on sync list size of list is 10
19/07/2017 16:29:38:796 DEBUG - getObserversFromCallId: done gathering observers
19/07/2017 16:29:38:796 DEBUG - CTIConnectorManager.dropCall: Call state of call 2337 is ACTIVE
19/07/2017 16:29:38:796 DEBUG - CTIConnectorManager.dropCall: Connection 0 state is CONNECTED
19/07/2017 16:29:38:796 DEBUG - CTIConnectorManager.dropCall: Connection 0 for address 4500
19/07/2017 16:29:38:796 DEBUG - CTIConnectorManager.dropCall: Connection 1 state is FAILED
19/07/2017 16:29:38:796 DEBUG - CTIConnectorManager.dropCall: Connection 1 for address 98123694237
19/07/2017 16:29:38:796 DEBUG - CTIConnectorManager.dropCall: Disconnecting connection for address 4500...
19/07/2017 16:29:38:796 DEBUG - CTICallObserver.doDisconnect:no UUI during disconnect for cid:com.avaya.sce.cticonnector.servlet.server.CallInfoData@18b7b14
19/07/2017 16:29:38:828 DEBUG - CTIConnectorManager.dropCall: Call com.avaya.jtapi.tsapi.impl.LucentV7CallImpl@1749450 dropped
19/07/2017 16:29:38:828 DEBUG - Mutex.setWait: wait is false
19/07/2017 16:29:38:828 DEBUG - CTICallObserver.callChangedEvent 4500: Event: 2 is 207 for call 2337 Provider:Acqueon
19/07/2017 16:29:38:828 DEBUG - CTICallObserver.callChangedEvent:4500: got Connection Failed Event
19/07/2017 16:29:38:828 DEBUG - CTICallObserver.callChangedEvent:4500: cause:100
19/07/2017 16:29:38:828 DEBUG - CTICallObserver.notifyApplicationObserver: Notifying 4500 about call event
19/07/2017 16:29:38:828 DEBUG - CTICallOperation.applicationCallEvent 4500: got a call failure
19/07/2017 16:29:38:828 DEBUG - Dial.StopCallTimer: Could find no timer to cancel for callid:2337
19/07/2017 16:29:38:828 DEBUG - getObserversFromCallId: gathering observers... done waiting on sync list size of list is 10
19/07/2017 16:29:38:828 DEBUG - CTICallOperation.makeCall 4500: Thread on mutex + resumed
19/07/2017 16:29:38:828 DEBUG - CTICallObserver.removeApplicationObserver: removing an app observer from extension:4500
19/07/2017 16:29:38:828 DEBUG - Dial.doDial 4500: Call ID for newly dialed call:2337
19/07/2017 16:29:38:874 DEBUG - getObserversFromCallId: done gathering observers
19/07/2017 16:29:38:874 DEBUG - CTIConnectorManager.dropCall: Call state of call 2337 is INVALID
19/07/2017 16:29:38:874 DEBUG - CTIConnectorManager.dropCall: Call com.avaya.jtapi.tsapi.impl.LucentV7CallImpl@1749450 dropped
19/07/2017 16:29:38:874 DEBUG - Mutex.setWait: wait is false
19/07/2017 16:29:38:874 DEBUG - CTICallObserver.callChangedEvent: Number of events on extension 4500 is 5
19/07/2017 16:29:38:874 DEBUG - CTICallObserver.callChangedEvent 4500: Event: 0 is 117 for call 2337 Provider:Acqueon
19/07/2017 16:29:38:874 DEBUG - CTICallObserver.callChangedEvent:4500: got an unknown event 117
19/07/2017 16:29:38:874 DEBUG - CTICallObserver.callChangedEvent 4500: Event: 1 is 215 for call 2337 Provider:Acqueon
19/07/2017 16:29:38:874 DEBUG - CTICallObserver.callChangedEvent:4500: got an unknown event 215
19/07/2017 16:29:38:874 DEBUG - CTICallObserver.callChangedEvent 4500: Event: 2 is 107 for call 2337 Provider:Acqueon
19/07/2017 16:29:38:874 DEBUG - CTICallObserver.callChangedEvent:4500: got Connection Disconnected Event 107
19/07/2017 16:29:38:874 DEBUG - CTICallObserver.callChangedEvent 4500: Event: 3 is 205 for call 2337 Provider:Acqueon
19/07/2017 16:29:38:874 DEBUG - CTICallObserver.callChangedEvent:4500: got Connection Disconnected Event 205
19/07/2017 16:29:38:874 DEBUG - CTICallObserver.callChangedEvent 4500: Event: 4 is 103 for call 2337 Provider:Acqueon
19/07/2017 16:29:38:874 DEBUG - CTICallObserver.callChangedEvent:4500: got Call Observation Ended Event
19/07/2017 16:29:38:874 DEBUG - CTICallObserver.removeCall:clearing MRCC:2337 from ext:4500
19/07/2017 16:29:38:874 DEBUG - CTICallObserver.removeCall:removing call:2337 from ext:4500
19/07/2017 16:29:44:865 DEBUG - ProviderMonitor: Checking:Acqueon for availability

Hi Wilson,

Thanks for your reply.

I have attached the log file for each scenario, please find more outbound application logs for references.
In case of customer number busy we are facing this problem. Normally if make a call in a number that number is free then application can process as expected.

Thanks

I don't see any problem with these calls. You made a conference call and aesconnect returned success

19/07/2017 16:40:12:256 DEBUG - B10EF05959573D1E31701E05AD7BF34D:/iAssistOutboundDialog_H323_VXML_2.2.1.8.0 : CTICommand.execute: request to manager is http://172.16.3.138:8080/aesconnector/Conference?heldcallid%3D2368%26activeCallId%3D2374%26extension%3D4500&k=BfXTOrU3QhO4qO7zNQcCgiOgHYr9kQBqbImHJFtFG3o%3D
19/07/2017 16:40:12:256 DEBUG - B10EF05959573D1E31701E05AD7BF34D:/iAssistOutboundDialog_H323_VXML_2.2.1.8.0 : CTICommand.execute: setting session cookie to B10EF05959573D1E31701E05AD7BF34D:/iAssistOutboundDialog_H323_VXML_2.2.1.8.0
19/07/2017 16:40:12:412 DEBUG - B10EF05959573D1E31701E05AD7BF34D:/iAssistOutboundDialog_H323_VXML_2.2.1.8.0 : CTICommand.execute: callinfo from Manager is callid=2368&ani= &dnis= &extension=4500&ucID=08720023681500460331&uui= &state=conferenced
19/07/2017 16:40:12:412 DEBUG - B10EF05959573D1E31701E05AD7BF34D:/iAssistOutboundDialog_H323_VXML_2.2.1.8.0 : CTICommand.processCallInfoResults: rawResponse: callid=2368&ani=+&dnis=+&extension=4500&ucID=08720023681500460331&uui=+&state=conferenced
19/07/2017 16:40:12:412 DEBUG - B10EF05959573D1E31701E05AD7BF34D:/iAssistOutboundDialog_H323_VXML_2.2.1.8.0 : CTICommand.setCallInfoVariableValues: State conferenced

Subsequently, you call the disconnect to disconnect the call from EP:

19/07/2017 16:40:21:881 DEBUG - B10EF05959573D1E31701E05AD7BF34D:/iAssistOutboundDialog_H323_VXML_2.2.1.8.0 : CTICommand.execute: request to manager is http://172.16.3.138:8080/aesconnector/Disconnect?callid%3D2374%26extension%3D4500&k=BfXTOrU3QhO4qO7zNQcCgmSw%2BxB4oIkywc8vyXEeSO8%3D
19/07/2017 16:40:21:881 DEBUG - B10EF05959573D1E31701E05AD7BF34D:/iAssistOutboundDialog_H323_VXML_2.2.1.8.0 : CTICommand.execute: setting session cookie to B10EF05959573D1E31701E05AD7BF34D:/iAssistOutboundDialog_H323_VXML_2.2.1.8.0
19/07/2017 16:40:21:959 DEBUG - B10EF05959573D1E31701E05AD7BF34D:/iAssistOutboundDialog_H323_VXML_2.2.1.8.0 : CTICommand.execute: callinfo from Manager is callid=2374&ani=4500&dnis=8123694237&extension=4500&ucID=08720023741500460343&uui= &state=disconnected
19/07/2017 16:40:21:959 DEBUG - B10EF05959573D1E31701E05AD7BF34D:/iAssistOutboundDialog_H323_VXML_2.2.1.8.0 : CTICommand.processCallInfoResults: rawResponse: callid=2374&ani=4500&dnis=8123694237&extension=4500&ucID=08720023741500460343&uui=+&state=disconnected
19/07/2017 16:40:21:959 DEBUG - B10EF05959573D1E31701E05AD7BF34D:/iAssistOutboundDialog_H323_VXML_2.2.1.8.0 : CTICommand.setCallInfoVariableValues: State disconnected

Then you call End which is not really necessary but it returned right away

19/07/2017 16:40:22:022 DEBUG - B10EF05959573D1E31701E05AD7BF34D:/iAssistOutboundDialog_H323_VXML_2.2.1.8.0 : CTICommand.execute: request to manager is http://172.16.3.138:8080/aesconnector/End?extension%3D4500%26callid%3D2368&k=BfXTOrU3QhO4qO7zNQcCghDufnY%2B7aFCbcdQJn%2BX25U%3D
19/07/2017 16:40:22:022 DEBUG - B10EF05959573D1E31701E05AD7BF34D:/iAssistOutboundDialog_H323_VXML_2.2.1.8.0 : CTICommand.execute: setting session cookie to B10EF05959573D1E31701E05AD7BF34D:/iAssistOutboundDialog_H323_VXML_2.2.1.8.0
19/07/2017 16:40:22:022 DEBUG - B10EF05959573D1E31701E05AD7BF34D:/iAssistOutboundDialog_H323_VXML_2.2.1.8.0 : CTICommand.execute: callinfo from Manager is
19/07/2017 16:40:22:022 DEBUG - B10EF05959573D1E31701E05AD7BF34D:/iAssistOutboundDialog_H323_VXML_2.2.1.8.0 : *** Reply for [/iAssistOutboundDialog_H323_VXML_2.2.1.8.0/Quit] ***
19/07/2017 16:40:22:022 DEBUG - B10EF05959573D1E31701E05AD7BF34D:/iAssistOutboundDialog_H323_VXML_2.2.1.8.0 : 0:<?xml version="1.0" encoding="UTF-8"?>

Hi Wilson,

Whatever log i have attached later those are working scenario's, i have just attached for reference.Customer number busy is only the case where our outbound application won't getting any response and timeout is happening. i have tested many times , it's giving same result in case of customer number is busy(Session timeout).

iAssistOutboundDialog_H323_VXML_2.2.1.8.0_CustDisconnectTheCall.log --> This file is for the case when customer phone is ringing and he is disconnecting the call.This is working scenario , we don't have any issue with this.

iAssistOutboundDialog_H323_VXML_2.2.1.8.0.log--> This file is for the normal case customer is picking the call and and talking with agent. This is working scenario.

iAssistOutboundDialog_H323_VXML_2.2.1.8.0_CustNumberBusy.log--> This log is for customer number busy case. This is the case where we are facing issues.


Please let me know if you need different set of log's for customer number busy scenario.

Thanks

I do need more busy scenario. Please post both the app trace.log and aes connector trace.log.

Hi Wilson,

Please find attached logs for customer number busy scenario.
in this log one call is success, where customer phone is ringing and customer is responding as expected.
the other call's are customer number busy.

Thanks

This doesn't look like a normal line-busy problem. It looks like the AES/TAPI is not responding or functioning properly. Do you do anything to it to try to simulate the "busy" situation?

25/07/2017 12:04:54:875 DEBUG - CTICallObserver.callChangedEvent:4501: Found connections object, but not 2 active connections. May be using FastConnect
25/07/2017 12:04:55:967 DEBUG - ProviderMonitor: Checking:CHNL_LIST for availability
25/07/2017 12:05:04:828 DEBUG - ProviderMonitor: Checking:CHNL_LIST for availability
25/07/2017 12:05:09:836 DEBUG - CTICallOperation.makeCall: Exception com.avaya.jtapi.tsapi.TsapiPlatformException: Could not meet post-conditions of connect()
25/07/2017 12:05:09:836 DEBUG - error type is 4 code is 0

Hi Wilson,

This testing scenario is a like ,

1) Requested a callback
2) We made ring in the call back number with other number(we made number busy).
3) Application is trying to make call in the callback number but the number is already busy.
4)Our application is getting timeout and not getting response from AES.

This is how we made customer busy.

Thanks

You would have to contact Avaya support AES/JTAPI team to see why the exception was raised.