Hi there,

At our JTAPI application, the ProviderObserver has been receiving the event of ProvShutdownEv which is very odd. I suppose this means the connection between JTAPI and AES is broken. My understanding of this is that JTAPI has some heartbeat message with AES. When the heartbeat failes to reach to AES, this is when this event is fired.

But my bottom line is that how can I figure out what is causing this? At my DEV and QA environment, it has been stable. But in my produciton environment, I am facing this ProvShutdownEv very often. So I am looking for advice to figure out what is wrong.

Is there any log level at JTAPI or AES that I can turn on to see more details?

Thanks for your help

Jamie

A Shutdown event is, I think, due to AE Services closing the TSAPI socket to the application because its output buffer has overrun. This is because the JTAPI client has not acknowledged events quickly enough.

The fact that you see a problem in production and not in your lab means that your problem is probably due to congestion under load. While this could be caused by network congestion or a lack of CPU/memory on AE Services or the application server, it is normally due to a flaw in the design of the application.

JTAPI applications use a Listener or Observer object to receive events in callback methods. The JTAPI client delivers events to the appropriate method using a single thread. This means that, if the application performs time-consuming operations in the callback, other events must wait in the incoming buffer. If this buffer overflows, events start to queue in the output buffer of AE Services.

The way to overcome this is to avoid processing events in the callback methods. Instead, take the incoming event and place it onto your own queue. You can then process the events using your own thread (or threads).

There is a very basic example of this design in the JTAPI AgentView sample application on the Devconnect website.

Martin

Thank you so much Martin for your response. I will look into the event handling side per your suggestion.

I have one more doubt. The same application in production used to run perfect without issues. Later we switch to a new installation of JTAPI application on a newer hardware and newer OS. But basically the JTAPI application is exactly intact and has no change at all. Then we start to observe this Shutdown event in this new environment context.

I was thinking if you can shed some light here for the direction of debugging.

By the way, I will examine the callback side per your suggestion.

Thanks again

Jamie

You could increase the trace level of the JTAPI client and see if anything interesting appears in the JTAPI traces. You can get information on this in the JTAPI Programmers Guide.

On the AE Services side, have a look in /var/log/avaya/aes . There are many log files there, though I am not sure which might have useful information. Usually, I suggest that people enable TSAPI traces and look at the log files in TSAPI folder. However, I think these only include message flow and do not give details of connection loss or errors.

I don't think you mentioned what version of AE Services you have and the logging seems to have changed lately so your logging folder may look different to mine. You may find the following useful, if they are available to you:

common/trace.out.N.gz (there are several log files & you will need to find which one covers the outage)
log.<date>
mvap.log
reset.log


If your application has been compliance tested by Devconnect, your customer can ask Avaya Client Services to investigate.

Martin

Hi Martin,

Thanks for your input. I have activated the trace file and I saw some strange outputs in the log files as shown below. I also atatched my settings of TSAPI.PRO and the log files for your reference. I am not sure what is wrong inside JTAPI. Any inputs will be grateful.

1. Here is the 1st thing I saw when we first received the shutdown
06/26/17 08:18:21.065 <DistributeCSTAEvent#4> Getting event CSTAEvent[CSTAOriginatedEvent]@3361ae54 for TSProvider[#1]@6093727d
06/26/17 08:18:21.065 <DistributeCSTAEvent#4> LucentV6OriginatedEvent ::=
06/26/17 08:18:21.065 <DistributeCSTAEvent#4> {
06/26/17 08:18:21.065 <DistributeCSTAEvent#4> physicalTerminal "8472"
06/26/17 08:18:21.065 <DistributeCSTAEvent#4> userInfo <null>
06/26/17 08:18:21.065 <DistributeCSTAEvent#4> }
06/26/17 08:18:21.065 <DistributeCSTAEvent#4> Handling CSTA_ORIGINATED for TSProvider[#1]@6093727d
06/26/17 08:18:21.065 <DistributeCSTAEvent#4> Event Distributor Exception - shutting down provider TSProvider[#1]@6093727d
06/26/17 08:18:21.065 <DistributeCSTAEvent#4> com.avaya.jtapi.tsapi.TsapiPlatformException: could not create terminal: 8472; device is not a terminal at com.avaya.jtapi.tsapi.TsapiTerminal.<init>(TsapiTerminal.java:965) at com.avaya.jtapi.tsapi.LucentTerminalImpl.<init>(LucentTerminalImpl.java:43) at com.avaya.jtapi.tsapi.TsapiPromoter.promoteTerminal(TsapiPromoter.java:135) at com.avaya.jtapi.tsapi.TSEventHandler.doConnEvents(TSEventHandler.java:1172) at com.avaya.jtapi.tsapi.TSEventHandler.cstaUnsolicited(TSEventHandler.java:245) at com.avaya.java.tsapiInterface.TsapiEventDistributor.handleEvent(TsapiEventDistributor.java:125) at com.avaya.java.tsapiInterface.TsapiEventQueue.run(TsapiEventQueue.java:96)TSProvider.shutdown - attempting shutdown
06/26/17 08:18:21.065 <DistributeCSTAEvent#4> TSProvider.shutdown - Starting
06/26/17 08:18:21.065 <DistributeCSTAEvent#4> Getting TsapiCallObserver lock to deliver deleteReference events for observer com.avaya.sms.JTAPICallObserver@40a1e297
06/26/17 08:18:21.065 <DistributeCSTAEvent#4> meta event BEGIN: cause (100) metaCode (136) for com.avaya.sms.JTAPICallObserver@40a1e297
06/26/17 08:18:21.065 <DistributeCSTAEvent#4> OBSERVATIONENDEDEVENT for observed: TSDevice[3048]@db7dce4, isTerminal? true for observer com.avaya.sms.JTAPICallObserver@40a1e297
06/26/17 08:18:21.065 <DistributeCSTAEvent#4> meta event END for com.avaya.sms.JTAPICallObserver@40a1e297 eventList size=1

2. I saw lots of errors that it tried to use the paramater of errorCount to be the hostname. NOTE! I am based on section 3.3 "JTAPI properties" in the programmer guide where there is a property of "errorCount" with the explanations of "Maximum number of error files". I suspect this is a mistake and the parameter name should be called "errorFileCount" instead of "errorCount". But it still use it for the hostname in the socket call.

06/25/17 18:44:43.767 {main} com.avaya.jtapi.tsapi.TsapiPlatformException: host <errorCount> not found at com.avaya.java.tsapiInterface.oio.TsapiChannelOio.trySocket(TsapiChannelOio.java:170) at com.avaya.java.tsapiInterface.oio.TsapiChannelOio.<init>(TsapiChannelOio.java:85) at com.avaya.java.tsapiInterface.oio.TsapiSessionFactoryOio.getLightweightTsapiSession(TsapiSessionFactoryOio.java:216) at com.avaya.java.tsapiInterface.TsapiSessionFactory.enumServices(TsapiSessionFactory.java:235) at com.avaya.java.tsapiInterface.TsapiSessionFactory.enumServices(TsapiSessionFactory.java:191) at com.avaya.java.tsapiInterface.TsapiSessionFactory.findTlink(TsapiSessionFactory.java:308) at com.avaya.java.tsapiInterface.Tsapi.<init>(Tsapi.java:132) at com.avaya.jtapi.tsapi.TSProvider.<init>(TSProvider.java:406) at com.avaya.jtapi.tsapi.TsapiProvider.<init>(TsapiProvider.java:30) at com.avaya.jtapi.tsapi.TsapiPeer.getProvider(TsapiPeer.java:36) at com.avaya.sms.JTAPIProxyServer.InitJTAPI(JTAPIProxyServer.java:128) at com.avaya.sms.JTAPIProxyServer.main(JTAPIProxyServer.java:703)enumServices() <errorFileSize>: com.avaya.jtapi.tsapi.TsapiPlatformException: host <errorFileSize> not found

Thanks

Jamie

Hi Jamie,

I can't tell much from the logs. The calls that cause problems do not look different to me than other calls.

However, the JTAPI Client that you are using is version 4.2.1. This has been obsolete for many years. Please upgrade to 6.3.x or 7.x and see if you still have problems.

Martin

BTW. You seem to be using Observer classes to get call events. These have been deprecated for several years. You should consider changing to using the Listeners.

Hi Martin,

Thanks for your response. We had been running this same combined version of AES and JTAPI for > 8 years and never had an issue. Since it was so reliable, our IT decided not to change it. After 8 years, they installed JTAPI client app to a new machine instance with the same binaries and we are now seeing this strange shutdown event.

So the above is the reason why it is this old version in use. I can talk to them to upgrade but this is in production and having some live impact to the users. So we are trying to resolve this at least to get the production going.

From the technical perspective, are we able to tell what cause the "TSProvider.shutdown" to trigger? I was using the trace level = 5 for this. Should I turn on trace level 7 to get to the bottom for this?

Special thanks

Jamie

I don't think debug level 7 will give any more information but feel free to try it.

If you need further help with this problem, you (or your customer) should open a support request with Avaya Client Services (ACS). Devconnect can only help with the development and testing of applications. Problems in deployment or production are handled by ACS.

Martin

Hi, I think we are one step closer.

After turnning on the log level 7 and set the heart beat timer to be 60 seconds, I am still seeing the provider shutdown. Also I didn't see any log like "...Heartbeat timer expired...." as in https://www.devconnectprogram.com/forums/posts/list/8804.page#p23406. So I am sure this is not the heartbeat timeout issue.

However, according to the log, as long as there is one event distribution error, JTAPI client library will initaite the shutdown itself based on the log exception below please see the highlight below. So I think we just need to figure out the error of "..... could not create terminal 3252; the device is not a termianl...". So what does this error mean?

08/02/17 07:10:05.093 <DistributeCSTAEvent#126> Event Distributor Exception - shutting down provider TSProvider[#2]@1d43627d
08/02/17 07:10:05.093 <DistributeCSTAEvent#126> com.avaya.jtapi.tsapi.TsapiPlatformException: could not create terminal: 3252; device is not a terminal
at com.avaya.jtapi.tsapi.TsapiTerminal.<init>(TsapiTerminal.java:965)
at com.avaya.jtapi.tsapi.LucentTerminalImpl.<init>(LucentTerminalImpl.java:43)
at com.avaya.jtapi.tsapi.TsapiPromoter.promoteTerminal(TsapiPromoter.java:135)
at com.avaya.jtapi.tsapi.TSEventHandler.doConnEvents(TSEventHandler.java:1172)
at com.avaya.jtapi.tsapi.TSEventHandler.cstaUnsolicited(TSEventHandler.java:245)
at com.avaya.java.tsapiInterface.TsapiEventDistributor.handleEvent(TsapiEventDistributor.java:125)
at com.avaya.java.tsapiInterface.TsapiEventQueue.run(TsapiEventQueue.java:96)TSProvider.shutdown - attempting shutdown
08/02/17 07:10:05.093 <DistributeCSTAEvent#126> TSProvider.shutdown - Starting
08/02/17 07:10:05.093 <DistributeCSTAEvent#126> Getting TsapiCallObserver lock to deliver deleteReference events for observer com.avaya.sms.JTAPICallObserver@425bfd9f
08/02/17 07:10:05.093 <DistributeCSTAEvent#126> meta event BEGIN: cause (100) metaCode (136) for com.avaya.sms.JTAPICallObserver@425bfd9f
08/02/17 07:10:05.093 <DistributeCSTAEvent#126> OBSERVATIONENDEDEVENT for observed: TSDevice[3048]@7f5f575c, isTerminal? true for observer com.avaya.sms.JTAPICallObserver@425bfd9f