Hi,

We are facing call drop on IVR application, we have checked and found no observer on extension in AES connector logs.

Customer is using failover for AES , while issue getting no observer on extension on both tlink, they are using insecure link since year and and this is facing from few days.

This is frequent issue which is comes every 4-5 days, we have raised ticket for AES but no issue found as per avaya support team.

As of now this is getting resolve post restart tomcat service.

kindly suggest

Definitely there is indication that both AES were down or not ping-able:

08/01/2021 11:31:04:089 DEBUG - ProviderMonitor: Checking:PuneAES for availability
08/01/2021 11:31:59:001 DEBUG - ProviderObserver.providerChangedEvent: got provider shutdown event:113
08/01/2021 11:31:59:001 DEBUG - CTICallObserver.callChangedEvent: Number of events on extension 25015 is 1
08/01/2021 11:31:59:001 DEBUG - CTICallObserver.callChangedEvent 25015: Event: 0 is 103 for call Provider:can't obtain
08/01/2021 11:31:59:001 DEBUG - CTICallObserver.callChangedEvent:25015: got Call Observation Ended Event
08/01/2021 11:32:04:102 DEBUG - ProviderMonitor:PuneAES got an exception getting date/time attempt:0 error:no conf event
08/01/2021 11:32:04:102 DEBUG - ProviderMonitor:PuneAES got a null getting date/time attempt:0
...

08/01/2021 11:32:59:014 DEBUG - CTICallObserver.callChangedEvent 25001: Event: 0 is 103 for call Provider:can't obtain
08/01/2021 11:32:59:014 DEBUG - CTICallObserver.callChangedEvent:25001: got Call Observation Ended Event
08/01/2021 11:32:59:014 DEBUG - CTICallObserver.callChangedEvent: Number of events on extension 25002 is 1
08/01/2021 11:32:59:014 ERROR - BlindCall.doBlindCall 25001: error attempting to disconnect caller com.avaya.sce.cticonnector.servlet.CTIConnectorException: Disconnect.doDisconnect: Call with id: 2821 is not available
08/01/2021 11:32:59:014 DEBUG - CTICallObserver.callChangedEvent 25002: Event: 0 is 103 for call Provider:can't obtain
08/01/2021 11:32:59:014 DEBUG - CTICallObserver.callChangedEvent:25002: got Call Observation Ended Event
08/01/2021 11:33:12:134 ERROR - No observer on extension:25009
08/01/2021 11:33:12:165 DEBUG - No callid found in CTIEnd
08/01/2021 11:33:12:165 ERROR - No observer on extension:25009

08/01/2021 11:37:24:215 DEBUG - ProviderMonitor:Mumbai AES got an exception getting date/time attempt:0 error:no conf event
08/01/2021 11:37:24:215 DEBUG - ProviderMonitor:Mumbai AES got a null getting date/time attempt:0

Can you help with Solutions...

Because this is facing after every 3-5 days, post restart tomcat its start functionality..

as we checked on network and server level and found no issue.

For the OD AES Connector point of view, the connection to AES got disrupted for some reason. You would need to get the JTAPI log and work with the Avaya AES support to further analyze it.

Hi Wilson,

We had faced same issue with other client also after checking with avaya backend and below is response for your reference.

****************************************************************

The JTAPI client periodically abort the connection with TSAPI connection with AES.

You need to check from AES connector side why it initial the connection disconnect request.

In below example, the connection set up at 10:42:48 and AES connector disconnect at 10:43:19 and send the re-connect request at 10:43:27.

<135>May 30 10:42:48 ccAES TSAPI[4948]: +06:00 2017 467 1 com.avaya.aes | csta_trace:Thread 0x9445db70 TSERVER Src: DRVR
<135>May 30 10:42:48 ccAES TSAPI[4948]: +06:00 2017 467 1 com.avaya.aes | csta_trace:Thread 0x9445db70 Login: "ctuser" App Name: "Jtapi Client" SessionID: 5507 Transport ID: 10.32.4.62
<135>May 30 10:42:48 ccAES TSAPI[4948]: +06:00 2017 467 1 com.avaya.aes | csta_trace:Thread 0x9445db70 InvokeID: 2
<135>May 30 10:42:48 ccAES TSAPI[4948]: +06:00 2017 467 1 com.avaya.aes | csta_trace:Thread 0x9445db70 Driver: AVAYA#BKASHCC#CSTA#CCAES
<135>May 30 10:42:48 ccAES TSAPI[4948]: +06:00 2017 467 1 com.avaya.aes | csta_trace:Thread 0x9445db70 Message:
<135>May 30 10:42:48 ccAES TSAPI[4948]: +06:00 2017 467 1 com.avaya.aes | csta_trace:Thread 0x9445db70 value ACSOpenStreamConfEvent ::=
<135>May 30 10:42:48 ccAES TSAPI[4948]: +06:00 2017 467 1 com.avaya.aes | csta_trace:Thread 0x9445db70 {
<135>May 30 10:42:48 ccAES TSAPI[4948]: +06:00 2017 467 1 com.avaya.aes | csta_trace:Thread 0x9445db70 apiVer "ST2",
<135>May 30 10:42:48 ccAES TSAPI[4948]: +06:00 2017 467 1 com.avaya.aes | csta_trace:Thread 0x9445db70 libVer "AES6.3.3.27",
<135>May 30 10:42:48 ccAES TSAPI[4948]: +06:00 2017 467 1 com.avaya.aes | csta_trace:Thread 0x9445db70 tsrvVer "7.0.1 Build 125",
<135>May 30 10:42:48 ccAES TSAPI[4948]: +06:00 2017 467 1 com.avaya.aes | csta_trace:Thread 0x9445db70 drvrVer "7.0.1 Build 125"
<135>May 30 10:42:48 ccAES TSAPI[4948]: +06:00 2017 467 1 com.avaya.aes | csta_trace:Thread 0x9445db70 }
<135>May 30 10:42:48 ccAES TSAPI[4948]: +06:00 2017 467 1 com.avaya.aes | csta_trace:Thread 0x9445db70
<135>May 30 10:42:48 ccAES TSAPI[4948]: +06:00 2017 469 1 com.avaya.aes | csta_trace:Thread 0x8e4ffb70 TSERVER Src: CLNT
<135>May 30 10:42:48 ccAES TSAPI[4948]: +06:00 2017 469 1 com.avaya.aes | csta_trace:Thread 0x8e4ffb70 Login: "ctuser" App Name: "Jtapi Client" SessionID: 5507 Transport ID: 10.32.4.62
<135>May 30 10:42:48 ccAES TSAPI[4948]: +06:00 2017 469 1 com.avaya.aes | csta_trace:Thread 0x8e4ffb70 InvokeID: 3
<135>May 30 10:42:48 ccAES TSAPI[4948]: +06:00 2017 469 1 com.avaya.aes | csta_trace:Thread 0x8e4ffb70 Driver: AVAYA#BKASHCC#CSTA#CCAES
<135>May 30 10:42:48 ccAES TSAPI[4948]: +06:00 2017 469 1 com.avaya.aes | csta_trace:Thread 0x8e4ffb70 Message:
<135>May 30 10:42:48 ccAES TSAPI[4948]: +06:00 2017 469 1 com.avaya.aes | csta_trace:Thread 0x8e4ffb70 value CSTAGetAPICaps ::=
<135>May 30 10:42:48 ccAES TSAPI[4948]: +06:00 2017 469 1 com.avaya.aes | csta_trace:Thread 0x8e4ffb70 {
<135>May 30 10:42:48 ccAES TSAPI[4948]: +06:00 2017 469 1 com.avaya.aes | csta_trace:Thread 0x8e4ffb70 null NULL
<135>May 30 10:42:48 ccAES TSAPI[4948]: +06:00 2017 469 1 com.avaya.aes | csta_trace:Thread 0x8e4ffb70 }
<135>May 30 10:42:48 ccAES TSAPI[4948]: +06:00 2017 469 1 com.avaya.aes | csta_trace:Thread 0x8e4ffb70


<135>May 30 10:43:19 ccAES TSAPI[4948]: +06:00 2017 238 1 com.avaya.aes | csta_trace:Thread 0x8e4ffb70 TSERVER Src: CLNT
<135>May 30 10:43:19 ccAES TSAPI[4948]: +06:00 2017 238 1 com.avaya.aes | csta_trace:Thread 0x8e4ffb70 Login: "ctuser" App Name: "Jtapi Client" SessionID: 5507 Transport ID: 10.32.4.62
<135>May 30 10:43:19 ccAES TSAPI[4948]: +06:00 2017 238 1 com.avaya.aes | csta_trace:Thread 0x8e4ffb70 Driver: AVAYA#BKASHCC#CSTA#CCAES
<135>May 30 10:43:19 ccAES TSAPI[4948]: +06:00 2017 238 1 com.avaya.aes | csta_trace:Thread 0x8e4ffb70 Message:
<135>May 30 10:43:19 ccAES TSAPI[4948]: +06:00 2017 238 1 com.avaya.aes | csta_trace:Thread 0x8e4ffb70 value ACSAbortStream ::=
<135>May 30 10:43:19 ccAES TSAPI[4948]: +06:00 2017 238 1 com.avaya.aes | csta_trace:Thread 0x8e4ffb70 {
<135>May 30 10:43:19 ccAES TSAPI[4948]: +06:00 2017 238 1 com.avaya.aes | csta_trace:Thread 0x8e4ffb70 null NULL
<135>May 30 10:43:19 ccAES TSAPI[4948]: +06:00 2017 238 1 com.avaya.aes | csta_trace:Thread 0x8e4ffb70 }
<135>May 30 10:43:19 ccAES TSAPI[4948]: +06:00 2017 238 1 com.avaya.aes | csta_trace:Thread 0x8e4ffb70

<135>May 30 10:43:27 ccAES TSAPI[4948]: +06:00 2017 371 1 com.avaya.aes | csta_trace:Thread 0x8e4ffb70 TSERVER Src: CLNT
<135>May 30 10:43:27 ccAES TSAPI[4948]: +06:00 2017 372 1 com.avaya.aes | csta_trace:Thread 0x8e4ffb70 Login: "ctuser" App Name: "Jtapi Client" SessionID: 5509 Transport ID: 10.32.4.62
<135>May 30 10:43:27 ccAES TSAPI[4948]: +06:00 2017 372 1 com.avaya.aes | csta_trace:Thread 0x8e4ffb70 InvokeID: 2
<135>May 30 10:43:27 ccAES TSAPI[4948]: +06:00 2017 372 1 com.avaya.aes | csta_trace:Thread 0x8e4ffb70 Driver: AVAYA#BKASHCC#CSTA#CCAES
<135>May 30 10:43:27 ccAES TSAPI[4948]: +06:00 2017 372 1 com.avaya.aes | csta_trace:Thread 0x8e4ffb70 Message:
<135>May 30 10:43:27 ccAES TSAPI[4948]: +06:00 2017 372 1 com.avaya.aes | csta_trace:Thread 0x8e4ffb70 value ACSOpenStream ::=
<135>May 30 10:43:27 ccAES TSAPI[4948]: +06:00 2017 372 1 com.avaya.aes | csta_trace:Thread 0x8e4ffb70 {
<135>May 30 10:43:27 ccAES TSAPI[4948]: +06:00 2017 372 1 com.avaya.aes | csta_trace:Thread 0x8e4ffb70 streamType stCsta,
<135>May 30 10:43:27 ccAES TSAPI[4948]: +06:00 2017 372 1 com.avaya.aes | csta_trace:Thread 0x8e4ffb70 serverID "AVAYA#BKASHCC#CSTA#CCAES",
<135>May 30 10:43:27 ccAES TSAPI[4948]: +06:00 2017 372 1 com.avaya.aes | csta_trace:Thread 0x8e4ffb70 loginID "ctuser",
<135>May 30 10:43:27 ccAES TSAPI[4948]: +06:00 2017 372 1 com.avaya.aes | csta_trace:Thread 0x8e4ffb70 cryptPass 'C076BDE868D3C13BDA1EA7A90BB3F847231EA7A90BB3F847231EA7A90BB3F84723 ...'H,
<135>May 30 10:43:27 ccAES TSAPI[4948]: +06:00 2017 372 1 com.avaya.aes | csta_trace:Thread 0x8e4ffb70 applicationName "Jtapi Client",
<135>May 30 10:43:27 ccAES TSAPI[4948]: +06:00 2017 372 1 com.avaya.aes | csta_trace:Thread 0x8e4ffb70 level acsLevel1,
<135>May 30 10:43:27 ccAES TSAPI[4948]: +06:00 2017 372 1 com.avaya.aes | csta_trace:Thread 0x8e4ffb70 apiVer "TS2",
<135>May 30 10:43:27 ccAES TSAPI[4948]: +06:00 2017 372 1 com.avaya.aes | csta_trace:Thread 0x8e4ffb70 libVer "AES6.3.3.27",
<135>May 30 10:43:27 ccAES TSAPI[4948]: +06:00 2017 372 1 com.avaya.aes | csta_trace:Thread 0x8e4ffb70 tsrvVer "7.0.1 Build 125"
<135>May 30 10:43:27 ccAES TSAPI[4948]: +06:00 2017 372 1 com.avaya.aes | csta_trace:Thread 0x8e4ffb70 }
<135>May 30 10:43:27 ccAES TSAPI[4948]: +06:00 2017 372 1 com.avaya.aes | csta_trace:Thread 0x8e4ffb70
<135>May 30 10:43:27 ccAES TSAPI[4948]: +06:00 2017 376 1 com.avaya.aes | csta_trace:Thread 0x9445db70 TSERVER Src: DRVR
<135>May 30 10:43:27 ccAES TSAPI[4948]: +06:00 2017 376 1 com.avaya.aes | csta_trace:Thread 0x9445db70 Login: "ctuser" App Name: "Jtapi Client" SessionID: 5509 Transport ID: 10.32.4.62
<135>May 30 10:43:27 ccAES TSAPI[4948]: +06:00 2017 376 1 com.avaya.aes | csta_trace:Thread 0x9445db70 Driver: AVAYA#BKASHCC#CSTA#CCAES
<135>May 30 10:43:27 ccAES TSAPI[4948]: +06:00 2017 376 1 com.avaya.aes | csta_trace:Thread 0x9445db70 Message:
<135>May 30 10:43:27 ccAES TSAPI[4948]: +06:00 2017 376 1 com.avaya.aes | csta_trace:Thread 0x9445db70 value ACSClientHeartbeatEvent ::=
<135>May 30 10:43:27 ccAES TSAPI[4948]: +06:00 2017 376 1 com.avaya.aes | csta_trace:Thread 0x9445db70 {
<135>May 30 10:43:27 ccAES TSAPI[4948]: +06:00 2017 376 1 com.avaya.aes | csta_trace:Thread 0x9445db70 null NULL
<135>May 30 10:43:27 ccAES TSAPI[4948]: +06:00 2017 376 1 com.avaya.aes | csta_trace:Thread 0x9445db70 }
<135>May 30 10:43:27 ccAES TSAPI[4948]: +06:00 2017 376 1 com.avaya.aes | csta_trace:Thread 0x9445db70
<135>May 30 10:43:27 ccAES TSAPI[4948]: +06:00 2017 376 1 com.avaya.aes | csta_trace:Thread 0x9445db70 TSERVER Src: DRVR
<135>May 30 10:43:27 ccAES TSAPI[4948]: +06:00 2017 376 1 com.avaya.aes | csta_trace:Thread 0x9445db70 Login: "ctuser" App Name: "Jtapi Client" SessionID: 5509 Transport ID: 10.32.4.62
<135>May 30 10:43:27 ccAES TSAPI[4948]: +06:00 2017 376 1 com.avaya.aes | csta_trace:Thread 0x9445db70 InvokeID: 2
<135>May 30 10:43:27 ccAES TSAPI[4948]: +06:00 2017 376 1 com.avaya.aes | csta_trace:Thread 0x9445db70 Driver: AVAYA#BKASHCC#CSTA#CCAES
<135>May 30 10:43:27 ccAES TSAPI[4948]: +06:00 2017 376 1 com.avaya.aes | csta_trace:Thread 0x9445db70 Message:
<135>May 30 10:43:27 ccAES TSAPI[4948]: +06:00 2017 376 1 com.avaya.aes | csta_trace:Thread 0x9445db70 value ACSOpenStreamConfEvent ::=
<135>May 30 10:43:27 ccAES TSAPI[4948]: +06:00 2017 376 1 com.avaya.aes | csta_trace:Thread 0x9445db70 {
<135>May 30 10:43:27 ccAES TSAPI[4948]: +06:00 2017 376 1 com.avaya.aes | csta_trace:Thread 0x9445db70 apiVer "ST2",
<135>May 30 10:43:27 ccAES TSAPI[4948]: +06:00 2017 376 1 com.avaya.aes | csta_trace:Thread 0x9445db70 libVer "AES6.3.3.27",
<135>May 30 10:43:27 ccAES TSAPI[4948]: +06:00 2017 376 1 com.avaya.aes | csta_trace:Thread 0x9445db70 tsrvVer "7.0.1 Build 125",
<135>May 30 10:43:27 ccAES TSAPI[4948]: +06:00 2017 376 1 com.avaya.aes | csta_trace:Thread 0x9445db70 drvrVer "7.0.1 Build 125"
<135>May 30 10:43:27 ccAES TSAPI[4948]: +06:00 2017 376 1 com.avaya.aes | csta_trace:Thread 0x9445db70 }
<135>May 30 10:43:27 ccAES TSAPI[4948]: +06:00 2017 376 1 com.avaya.aes | csta_trace:Thread 0x9445db70

*********************************************************



This kind of issue we are getting frequent and with multiple customer , no issue found post checking the aes connectivity also with same tlink other product is working fine where we are not using aesconnector.

Kindly help us to diagnose the issue from aesconnector end.

I wonder what happens between 10:43:19 and 10:43:27. Normally the AES Connector would not shutdown the connection unless detects a problem by pinging the AES constantly. You would see a message in the AES Connector log like this "got an exception getting date/time attempt".
Could you show the AES Connector log for the time frame between 10:43:19 and 10:43:27?

Hi Wilsone,

We don't have aes connector logs at mention time period as this was older client.

But we are facing the same error and below attached logs is for your refrence.

*****************************************

14/04/2021 14:10:28:585 DEBUG - CTICallObserver.removeAllCallsFrom:clearing out MRCR
14/04/2021 14:10:28:585 DEBUG - CTICallObserver.removeAllCallsFrom:removed all calls from extension:5025
14/04/2021 14:10:28:585 DEBUG - CTICallObserver.removeAllCallsFromCache:removed all calls from cache at extension:5025
14/04/2021 14:10:28:585 DEBUG - ProviderObserver.providerChangedEvent:AES-S-IVR is added to list of downed providers
14/04/2021 14:10:28:585 DEBUG - ProviderObserver.providerChangedEvent: JTAPI Provider is down
14/04/2021 14:10:38:898 ERROR - No observer on extension:5025
14/04/2021 14:10:43:663 DEBUG - ProviderMonitor:AES-S-IVR got an exception getting date/time attempt:1 error:client not in service
14/04/2021 14:10:43:663 DEBUG - ProviderMonitor:AES-S-IVR got a null getting date/time attempt:1
14/04/2021 14:10:47:351 ERROR - Hold.doHold:There is no longer an observer for this call - 5015:8258; it could be that the platform port has been disconnected from this call
14/04/2021 14:10:47:866 ERROR - No observer on extension:5015
14/04/2021 14:10:48:507 DEBUG - No callid found in CTIEnd
14/04/2021 14:10:48:507 ERROR - No observer on extension:5025
14/04/2021 14:10:49:116 ERROR - Hold.doHold:There is no longer an observer for this call - 5024:8259; it could be that the platform port has been disconnected from this call
14/04/2021 14:10:49:632 ERROR - No observer on extension:5024
14/04/2021 14:11:03:663 DEBUG - ProviderMonitor:AES-S-IVR got an exception getting date/time attempt:2 error:client not in service
14/04/2021 14:11:03:663 DEBUG - ProviderMonitor:AES-S-IVR got a null getting date/time attempt:2
14/04/2021 14:11:05:819 ERROR - No observer on extension:5004
14/04/2021 14:11:10:054 ERROR - No observer on extension:5021
14/04/2021 14:11:14:241 DEBUG - No callid found in CTIEnd
14/04/2021 14:11:14:241 ERROR - No observer on extension:5021
14/04/2021 14:11:15:460 DEBUG - No callid found in CTIEnd
14/04/2021 14:11:15:460 ERROR - No observer on extension:5004
14/04/2021 14:11:23:663 DEBUG - ProviderMonitor:AES-S-IVR got an exception getting date/time attempt:3 error:client not in service
14/04/2021 14:11:23:663 DEBUG - ProviderMonitor:AES-S-IVR got a null getting date/time attempt:3
14/04/2021 14:11:26:304 ERROR - Hold.doHold:There is no longer an observer for this call - 5011:8261; it could be that the platform port has been disconnected from this call
14/04/2021 14:11:26:819 ERROR - No observer on extension:5011
14/04/2021 14:11:28:351 ERROR - No observer on extension:5005
14/04/2021 14:11:37:960 DEBUG - No callid found in CTIEnd
14/04/2021 14:11:37:960 ERROR - No observer on extension:5005
14/04/2021 14:11:43:663 ERROR - No dateTime found. No connection to server
14/04/2021 14:11:43:663 DEBUG - ProviderMonitor:remove provider from the list.
14/04/2021 14:11:51:663 DEBUG - ProviderMonitor: Checking:AES-S-IVR for availability
14/04/2021 14:11:51:663 DEBUG - ProviderMonitor:AES-S-IVR is null in our list, attempt to reget
14/04/2021 14:11:51:804 DEBUG - CTIConnectorManager.getConnectionString: No entry for TServer in configuration file
14/04/2021 14:11:51:804 DEBUG - CTIConnectorManager.initProvider: Look for TServer config in DD application configuration (new method to 4.0)
14/04/2021 14:11:51:804 DEBUG - CTIConnectorManager.ConfigureFromConfigurationFile: getting provider:AVAYA#UCBCC#CSTA-S#UCCDCAES
14/04/2021 14:11:51:882 DEBUG - CTIConnectorManager.ConfigureFromConfigurationFile: provider obtained
14/04/2021 14:11:51:882 DEBUG - CTIConnectorManager.ConfigureFromConfigurationFile: give provider cycles:40 of delay:100ms
14/04/2021 14:11:51:882 DEBUG - CTIConnectorManager.ConfigureFromConfigurationFile: provider is not in service -- STATE: 1, give small delay
14/04/2021 14:11:51:991 DEBUG - CTIConnectorManager.ConfigureFromConfigurationFile: provider is now in service -- STATE: 2
14/04/2021 14:11:51:991 DEBUG - CTIConnectorManager.ConfigureFromConfigurationFile: provider is now in service -- STATE: 2
14/04/2021 14:11:51:991 DEBUG - CTIConnectorManager.initProvider: provider vendor version is

************************************************************

Kindly suggest if any logs or any troubleshooting can be done on aesconnector.

That is exactly the error I was expecting.

14/04/2021 14:10:43:663 DEBUG - ProviderMonitor:AES-S-IVR got an exception getting date/time attempt:1 error:client not in service
14/04/2021 14:10:43:663 DEBUG - ProviderMonitor:AES-S-IVR got a null getting date/time attempt:1

AES Connector is calling the JTAPI api method(below) and gets an exception with the "client not in service" message" from JTAPI. You would have to look into the TSAPI log for the error and loop back to AES support since they have to look at this error.

com.avaya.jtapi.tsapi.LucentProvider.getSwitchDateAndTime();