Hello,

we are getting an error unexpectedly on a running system with AES version 4.0 , service provider dll version 4.1 . we noticed that after running the application for 2 days and every day early morning 3AM -4 AM our applicaiton will lose connection to AES server, if we try to reconnect it will give us error "Unable to read from socket. Socket to server has been closed" . To recover from this error , we need to restart the AES server. Is there any way to resolve this. Please get back to me at the earliest as this is bit critical for us.

Thanks and Regards
Abdul Rasheed

Ultimately, AE Services 4.x is no longer supported, and you may need to upgrade to get support.

With that said is this a production site, or lab issue? If it is a production site, please contact Avaya Customer Services (www.avaya.com/support) and open a trouble ticket with them.

Examine the AEServices /opt/mvap/logs/dmcc-trace.log.x file for the corresponding time window and see what DMCC software thinks happened.

Enable logging in the .NET SDK, and see what it thinks happened.

Setup an ethereal sniff near your application, and on the AE Services side, and see what it thinks happened.

Dear Johnson,

TSAPI client application some times fails with error in the log "private message UNKNOWN(65535) was found.
02:50:42 ERROR:WARNING:TSAPI:g3pderr:E_WARNING:L 1074:C 38:[CAS.CPP]: For message [MONITOR_DEVICE:111] an inappropriate or unknown private message UNKNOWN(65535) was found.
02:50:42 "

We are using TSAPI client 4.2 and AES version 4.0 , will that be a reason for the above error. When the above error happens, our tsapi application will restart the DMCC application as a recovery measure , and as this tsapi error is occuring many times, DMCC application will get restarted many times and finally result in a socket close error. Following are the MVAP logs which i noticed during the DMCC failture of socket.


INFO: [1566:najmpbx:10.1.5.200:0] :session[session 1D07E41E68BF78B83DCADB158FDDC9E8-3] Client API call
2013-02-23 02.51.40,104 com.avaya.mvcs.monitor.MonitoringServicesImpl stopMonitor
FINE: removing MediaControlListener: 92:[Holder]: [1566:najmpbx:10.1.5.200:0] ,com.avaya.mvcs.monitor.MediaControlListenerImpl@6f8860
2013-02-23 02.51.40,105 com.avaya.mvap.intsvc.CstaTerminalImpl tearDownDevice
FINE: [10.1.5.200:1566] station is now clear
2013-02-23 02.51.40,105 com.avaya.mvap.extsvc.DeviceServicesImpl releaseDeviceID
INFO: session[session 1D07E41E68BF78B83DCADB158FDDC9E8-3] session released device [1566:najmpbx:10.1.5.200:0] via Client API call
2013-02-23 02.51.40,105 com.avaya.mvcs.proxy.CstaRouterNode processPacket
FINE: Received session[null] com.avaya.csta.binding.ReleaseDeviceIdResponse@1d3c40c in response to session[session 1D07E41E68BF78B83DCADB158FDDC9E8-3] com.avaya.csta.binding.ReleaseDeviceId@32b816
2013-02-23 02.51.40,135 com.avaya.common.packet.TPacketizer readChannel
INFO: End of stream from DefaultTCPChannel Bound to SocketAddress: /10.1.5.194:4721 Connected to SocketAddress: /172.16.0.146:1280
2013-02-23 02.51.40,135 com.avaya.mvcs.proxy.ExceptionEventHandlerNode handleEvent
FINE: Normal Operation: The far end closed the socket, event=ExceptionEvent[com.avaya.mvcs.proxy.TPacketReaderNode@134d246, com.avaya.common.packet.EndOfStreamException: End of stream from DefaultTCPChannel Bound to SocketAddress: /10.1.5.194:4721 Connected to SocketAddress: /172.16.0.146:1280, session[session 1D07E41E68BF78B83DCADB158FDDC9E8-3,DefaultTCPChannel Bound to SocketAddress: /10.1.5.194:4721 Connected to SocketAddress: /172.16.0.146:1280]]
2013-02-23 02.51.40,145 com.avaya.mvcs.proxy.CstaRouterNode handlePipelineCommand
FINE: Socket is closed, so pausing event subscriptions for session=session[session 1D07E41E68BF78B83DCADB158FDDC9E8-3,DefaultTCPChannel Bound to SocketAddress: /10.1.5.194:4721 Not connected.]
2013-02-23 02.51.40,146 com.avaya.mvcs.proxy.TPacketReaderNode handlePipelineCommand
INFO: Closing channel=DefaultTCPChannel Bound to SocketAddress: /10.1.5.194:4721 Not connected. and marking session=session 1D07E41E68BF78B83DCADB158FDDC9E8-3 as inactive
2013-02-23 02.51.40,147 com.avaya.sessionsvc.SessionObjectImpl markAsInactive
FINE: session 1D07E41E68BF78B83DCADB158FDDC9E8-3 is being marked as inactive.
2013-02-23 02.51.40,148 com.avaya.mvcs.proxy.CstaMarshallerNode$CstaMarshallerThread convertException
FINE: Returning negative ack to client session (1D07E41E68BF78B83DCADB158FDDC9E8-3) : com.avaya.csta.errors.InvalidSessionIDException: com.avaya.api.sessionsvc.exceptions.SessionInactiveException: Session = 1D07E41E68BF78B83DCADB158FDDC9E8-3 :: request = session[null] ch.ecma.csta.binding.stop.StopApplicationSession@1ebf1ca
2013-02-23 02.51.40,160 com.avaya.mvcs.proxy.ByteBufferToChannelNode processPacket
FINE: Unable to write to socket: packet=com.avaya.common.packet.TPacket@14f279c, session=session[session 1D07E41E68BF78B83DCADB158FDDC9E8-3,DefaultTCPChannel Bound to SocketAddress: /10.1.5.194:4721 Not connected.]
2013-02-23 02.51.40,160 com.avaya.mvcs.proxy.ExceptionEventHandlerNode handleEvent
FINE: Unknown Operation: The socket was already closed when a write was attempted... We're closing the near end of the socket, but session may not be affected, event=ExceptionEvent[com.avaya.mvcs.proxy.ByteBufferToChannelNode@14f79cb, java.nio.channels.ClosedChannelException, session[session 1D07E41E68BF78B83DCADB158FDDC9E8-3,DefaultTCPChannel Bound to SocketAddress: /10.1.5.194:4721 Not connected.]]
2013-02-23 02.51.40,161 com.avaya.mvcs.proxy.CstaRouterNode handlePipelineCommand
FINE: Socket is closed, so pausing event subscriptions for session=session[session 1D07E41E68BF78B83DCADB158FDDC9E8-3,DefaultTCPChannel Bound to SocketAddress: /10.1.5.194:4721 Not connected.]
2013-02-23 02.51.40,161 com.avaya.mvcs.proxy.TPacketReaderNode handlePipelineCommand
INFO: Closing channel=DefaultTCPChannel Bound to SocketAddress: /10.1.5.194:4721 Not connected. and marking session=session 1D07E41E68BF78B83DCADB158FDDC9E8-3 as inactive
2013-02-23 02.51.45,148 com.avaya.sessionsvc.CleanupTimerTask run
FINE: CleanupTimerTask cleaning up: session 1D07E41E68BF78B83DCADB158FDDC9E8-3
2013-02-23 02.51.45,148 com.avaya.mvcs.proxy.CstaRouterNode$MySessionListener sessionCleanedup
FINE: Session is cleaned up, removing subscription for: session 1D07E41E68BF78B83DCADB158FDDC9E8-3
2013-02-23 02.51.45,149 com.avaya.mvcs.proxy.SubscriptionManager unsubscribeAll
FINE: calling unsubscribe 92
2013-02-23 02.51.45,149 com.avaya.mvcs.proxy.SubscriptionManager unsubscribeAll
FINE: calling unsubscribe 102
2013-02-23 02.51.45,149 com.avaya.mvcs.proxy.SubscriptionManager unsubscribeAll
FINE: calling unsubscribe 94
2013-02-23 02.51.45,149 com.avaya.mvcs.proxy.SubscriptionManager unsubscribeAll
FINE: calling unsubscribe 104
2013-02-23 02.51.45,149 com.avaya.mvcs.proxy.SubscriptionManager unsubscribeAll
FINE: calling unsubscribe 84
2013-02-23 02.51.45,149 com.avaya.mvcs.proxy.SubscriptionManager unsubscribeAll
FINE: calling unsubscribe 86
2013-02-23 02.51.45,149 com.avaya.mvcs.proxy.SubscriptionManager unsubscribeAll
FINE: calling unsubscribe 96
2013-02-23 02.51.45,150 com.avaya.mvcs.proxy.SubscriptionManager unsubscribeAll
FINE: calling unsubscribe 106
2013-02-23 02.51.45,172 com.avaya.mvcs.proxy.SubscriptionManager unsubscribeAll
FINE: calling unsubscribe 108
2013-02-23 02.51.45,172 com.avaya.mvcs.proxy.SubscriptionManager unsubscribeAll
FINE: calling unsubscribe 90
2013-02-23 02.51.45,172 com.avaya.mvcs.proxy.SubscriptionManager unsubscribeAll
FINE: calling unsubscribe 110
2013-02-23 02.51.45,173 com.avaya.mvcs.proxy.SubscriptionManager unsubscribeAll
FINE: calling unsubscribe 88
2013-02-23 02.51.45,173 com.avaya.mvcs.proxy.SubscriptionManager unsubscribeAll
FINE: calling unsubscribe 100
2013-02-23 02.51.45,173 com.avaya.mvcs.proxy.SubscriptionManager unsubscribeAll
FINE: calling unsubscribe 98
2013-02-23 02.51.45,173 com.avaya.mvcs.proxy.SubscriptionManager unsubscribeAll
INFO: Clearing the executor



Thanks and Regards
Rasheed

That "unknown private message" error sounds like a private data issue. Make sure that you are using the proper private data structures based on the private data version that is getting negotiated in the TSAPI Open Stream.

View the TSAPI programmers guide for information on what Private Data versions are supported with your AE Services version.

The TSAPI client has a tool called TSSPY that will trace any open streams created on your client machine. This way you can see the acsOpenStream, and the confirmation that comes back which tells you what private data version was negotiated.

Dear Johnson,

If there is a private data version issue, will that cause to hang the connection between applicaion and AES server? If the version of TSAPI client is 4.2 and aes is 4.0 , will that cause an issue?

Regards
Rasheed

The only way to tell that would be through the logs and see if TSAPI is detecting errors at such a high rate that it's shutting down. Or are these errors the result of the shutdown. From your previous post it sounded like you were seeing the former behavior.

It's not really a problem for TSAPI 4.2 and AE Services 4.0 to be talking here. The issue is more the versions overall are very old, and not supported.

I would suggest upgrading to a more recent version of the software, as it's not wise to troubleshoot an issue that may not be occurring on newer versions.

You do have that one private data error issue, and I would suggest at least making sure that you fix it, and that will tell you if that was causing the problem or not.