I have checked logs for 2 samples extension extesnion_0606 and extesnion_9292.
I have attached logs for the same extension for more details.
Here I will explain you what may cause this issue,
Lets take an example of extesnion_0606 as below,
Operation event logs
#1
<14>Jun 18 06:57:57 domainname.com SipEngine[3231]: +04:00 2019 198 1 com.avaya.asm | 1 com.avaya.asm.core OP_CURE57001 User sip:extesnion_0606@A.B.C.26:52043;transport=tls;avaya-sc-enabled has registered.
14>Jun 18 06:59:51 domainname.com SipEngine[3231]: +04:00 2019 extesnion_060 1 com.avaya.asm | 1 com.avaya.asm.core OP_CURE57004 Unregistering user sip:extesnion_0606@A.B.C.26:52043;transport=tls;avaya-sc-enabled due to duplicate user registration. Only one active user is allowed with the current forking policy.
Asset logs
#1
Jun 18 06:59:41 HOSTNAMESM01 AasSipMgr[4137]: prv/src/AslConnector.cpp::connectDone(291:AslConnector_4169):Connect to LP.Q.R.135:32321/RA.B.C.26:52043/TLS/0x9f192 failed due to connect timeout
Jun 18 06:59:45 HOSTNAMESM01 AasSipMgr[4137]: prv/src/AslTcpConnection.cpp::writeToSocket(448:AslDataProcesso_4165):Resetting stuck socket LP.Q.R.135:5061/RA.B.C.35:48658/TLS/0x9f17f after 6 consecutive TCP retransmit timeouts.
Operation event logs
#2
<14>Jun 18 18:40:15 domainname.com SipEngine[3231]: +04:00 2019 680 1 com.avaya.asm | 1 com.avaya.asm.core OP_CURE57004 Unregistering user sip:extesnion_0606@A.B.C.26:extesnion_92025;transport=tls;avaya-sc-enabled due to duplicate user registration. Only one active user is allowed with the current forking policy.
<14>Jun 18 18:40:15 domainname.com SipEngine[3231]: +04:00 2019 682 1 com.avaya.asm | 1 com.avaya.asm.core OP_CURE57001 User sip:extesnion_0606@A.B.C.26:41987;transport=tls;avaya-sc-enabled has registered.
<14>Jun 18 19:03:35 domainname.com SipEngine[3231]: +04:00 2019 677 1 com.avaya.asm | 1 com.avaya.asm.core OP_CURE57004 Unregistering user sip:extesnion_0606@A.B.C.26:41987;transport=tls;avaya-sc-enabled due to duplicate user registration. Only one active user is allowed with the current forking policy.
<14>Jun 18 19:03:35 domainname.com SipEngine[3231]: +04:00 2019 679 1 com.avaya.asm | 1 com.avaya.asm.core OP_CURE57001 User sip:extesnion_0606@A.B.C.26:37225;transport=tls;avaya-sc-enabled has registered.
<14>Jun 18 19:06:30 domainname.com SipEngine[3231]: +04:00 2019 620 1 com.avaya.asm | 1 com.avaya.asm.core OP_CURE57004 Unregistering user sip:extesnion_0606@A.B.C.26:37225;transport=tls;avaya-sc-enabled due to duplicate user registration. Only one active user is allowed with the current forking policy.
<14>Jun 18 19:06:30 domainname.com SipEngine[3231]: +04:00 2019 621 1 com.avaya.asm | 1 com.avaya.asm.core OP_CURE57001 User sip:extesnion_0606@A.B.C.26:45828;transport=tls;avaya-sc-enabled has registered.
Asset logs
#2
Similarly I have checked during 18:00 hours till it stabilize
Jun 18 18:39:56 HOSTNAMESM01 AasSipMgr[4137]: prv/src/AslTcpConnection.cpp::diagnoseFailure(246:AslDataListener_4173):LP.Q.R.135:5061/RA.B.C.26:extesnion_92025/TLS/0x9f42d: read failed, errno[104] - Connection reset by peer
Jun 18 18:47:46 HOSTNAMESM01 AasSipMgr[4137]: prv/src/AslTcpConnection.cpp::diagnoseFailure(246:AslDataListener_4174):LP.Q.R.135:5061/RA.B.C.26:37529/TLS/0x9fc3e: accept failed, errno[0] - Success
Jun 18 18:47:46 HOSTNAMESM01 AasSipMgr[4137]: prv/src/AslTlsConnection.cpp::close(122:AslDataListener_4174):SSL_shutdown() failed, Connection LP.Q.R.135:5061/RA.B.C.26:37529/TLS/0x9fc3e fd=1696 error:00000000:lib(0):func(0):reason(0)
Jun 18 18:48:01 HOSTNAMESM01 AasSipMgr[4137]: prv/src/AslTcpConnection.cpp::diagnoseFailure(246:AslDataListener_4174):LP.Q.R.135:5061/RA.B.C.26:57697/TLS/0x9fc46: accept failed, errno[0] - Success
Jun 18 18:48:01 HOSTNAMESM01 AasSipMgr[4137]: prv/src/AslTlsConnection.cpp::close(122:AslDataListener_4174):SSL_shutdown() failed, Connection LP.Q.R.135:5061/RA.B.C.26:57697/TLS/0x9fc46 fd=1740 error:00000000:lib(0):func(0):reason(0)
Jun 18 18:48:22 HOSTNAMESM01 AasSipMgr[4137]: prv/src/AslTcpConnection.cpp::diagnoseFailure(246:AslDataListener_4174):LP.Q.R.135:5061/RA.B.C.26:9133/TLS/0x9fc55: accept failed, errno[0] - Success
Jun 18 18:48:22 HOSTNAMESM01 AasSipMgr[4137]: prv/src/AslTlsConnection.cpp::close(122:AslDataListener_4174):SSL_shutdown() failed, Connection LP.Q.R.135:5061/RA.B.C.26:9133/TLS/0x9fc55 fd=1785 error:00000000:lib(0):func(0):reason(0)
Jun 18 18:49:51 HOSTNAMESM01 AasSipMgr[4137]: prv/src/AslTcpConnection.cpp::writeToSocket(448:AslDataProcesso_4164):Resetting stuck socket LP.Q.R.135:5061/RA.B.C.26:32204/TLS/0x9fc62 after 5 consecutive TCP retransmit timeouts.
Jun 18 18:50:22 HOSTNAMESM01 AasSipMgr[4137]: prv/src/AslConnector.cpp::connectDone(281:AslConnector_4169):connect to LP.Q.R.135:52597/RA.B.C.26:32204/TLS/0x9fc83 took 31 sec
Jun 18 18:50:22 HOSTNAMESM01 AasSipMgr[4137]: prv/src/AslConnection.cpp::addMessage(361:AslConnector_4169):Connection to LP.Q.R.135:52597/RA.B.C.26:32204/TLS/0x9fc83 not serviced by peer for 31 seconds. Closing connection
Jun 18 18:50:22 HOSTNAMESM01 AasSipMgr[4137]: prv/src/AslConnector.cpp::connectDone(291:AslConnector_4169):Connect to LP.Q.R.135:52597/RA.B.C.26:32204/TLS/0x9fc83 failed due to connect timeout
I can see same behavior for all the extension in the A.B.C.* range in asset logs from session manager where it says “timed out” or connection reset by peer” or it took more than “32” seconds to reestablish connection.
As this logs from session manager end we can see times out from phone. This kind of issue come due to network glitch for a couple of minutes.
As we can see only one side affected so we can take out ASM out of the picture and clearly see phone and ASM communication have problem during same time period.
I have see same issue for different customer where it turn to be network issue,
