1
Mitel MiVoice Business/MCD/3300 / Re: Strange issue with intermittent disconnects on interflowed calls
« on: August 06, 2017, 01:16:34 AM »
==SIP Logs - From Overflow Center's PBX==
Code: [Select]
8/4/17 17:43:54
ANI 8005116880
740-855-5251 DNIS 1008171
Snippet from C:\Users\Tomu-admin\Desktop\080417_SIP\SIPEngine.ininlog
Message Timestamp (UTC-04:00) Topic Thread
SIPHandlerIO::submit_recvd_message : *?INV$(P#266415) - udp recv 10.###.46.102:5060 <- 10.21.4.125:5060 (retried-request) msg=
INVITE sip:1008171@10.21.46.102;transport=udp SIP/2.0
Via: SIP/2.0/UDP 10.21.4.125:5060;branch=z9hG4bKb3725ac4b6877f55dc8292388, SIP/2.0/UDP 172.31.154.77:5085;branch=z9hG4bKrjpn7a108gsg4rtvffg0.1
To: <sip:1008171@garfield.infocisionprod.globalipcom.com>
Content-Type: application/sdp
Allow: INVITE, ACK, BYE, OPTIONS, CANCEL, SUBSCRIBE, REFER
Accept: application/sdp
Call-ID: wlss-fcc72a0b-0ba58fac67af5f76@152.188.161.36
From: <sip:8005116880@74.80.226.163>;tag=e181103b
Date: Fri, 04 Aug 2017 21:43:55 GMT
Contact: <sip:8005116880@172.31.154.77:5085;sipappsessionid=app-1tym8ppll31n9;transport=udp>
Ncp-Prcd: ICT
Allow-Events: refer
Supported: replaces, timer
Accept-Encoding:
Accept-Language: en
Privacy: none
Max-Forwards: 68
Session-Expires: 1800;refresher=uac
CSeq: 1 INVITE
Content-Length: 221
P-Asserted-Identity: UNAVAILABLE <sip:+18005116880@65.211.120.237>
Record-Route: <sip:10.21.4.125:5060;lr;transport=udp>
v=0
o=MediaServer 3710871835 3710871836 IN IP4 172.31.154.196
s=-
i=Media Server version 2,0,0,238
c=IN IP4 172.31.154.196
t=0 0
m=audio 20300 RTP/AVP 0
c=IN IP4 172.31.154.196
a=sendrecv
a=rtpmap:0 PCMU/8000/1 17:43:54.8691133_0001 SIPEngine.Packets 0x27bc
SIPRequestInstance::SIPRequestInstance : inbound-leg: SIPCallLeg {
to/remote: <sip:8005116880@74.80.226.163>;tag=e181103b
from/local: <sip:1008171@garfield.infocisionprod.globalipcom.com>;tag=ch4cnjq
callID: wlss-fcc72a0b-0ba58fac67af5f76@152.188.161.36}
17:43:54.8716133_0004 SIPEngine.Processing 0x18cc
SIPSession::updateDestination : callID=wlss-fcc72a0b-0ba58fac67af5f76@152.188.161.36, old destination=10.21.4.125:5060
new destination=SIPViaUrl { host: "10.21.4.125" port: "5060" ttl: "" maddr: "" received: "" rport: "" branch: "z9hG4bKb3725ac4b6877f55dc8292388" transport: "udp" hidden: "false" generic-param { } } 17:43:54.8716133_0017 SIPEngine.Processing 0x1998
SIPSession::recordRoute : callID=wlss-fcc72a0b-0ba58fac67af5f76@152.188.161.36, total route entries=2, route=SIPRouteUrl { displayName: "" generic-param { } SIPUrl { phone: 0 scheme: "sip" user: "8005116880" passwd: "" host: "172.31.154.77" port: "5085" transport: "udp" userparam: "ip" method: "INVITE" maddr: "" other-param { sipappsessionid: "app-1tym8ppll31n9" } headers { } original: "sip:8005116880@172.31.154.77:5085;sipappsessionid=app-1tym8ppll31n9;transport=udp" } }, SIPRouteUrl { displayName: "" generic-param { } SIPUrl { phone: 0 scheme: "sip" user: "" passwd: "" host: "10.21.4.125" port: "5060" transport: "udp" userparam: "ip" method: "INVITE" maddr: "" other-param { } headers { } original: "sip:10.21.4.125:5060;lr;transport=udp" } } 17:43:54.8716133_0034 SIPEngine.Processing 0x1998
SIPUDPHandlerIO::issue_msg_write : S#145407: (P#266417)*100->INV$(P#266415) - udp xmit 10.21.46.102:5060 -> 10.21.4.125:5060 [410] msg=
SIP/2.0 100 Trying
To: <sip:1008171@garfield.infocisionprod.globalipcom.com>
From: <sip:8005116880@74.80.226.163>;tag=e181103b
Via: SIP/2.0/UDP 10.21.4.125:5060;branch=z9hG4bKb3725ac4b6877f55dc8292388, SIP/2.0/UDP 172.31.154.77:5085;branch=z9hG4bKrjpn7a108gsg4rtvffg0.1
CSeq: 1 INVITE
Call-ID: wlss-fcc72a0b-0ba58fac67af5f76@152.188.161.36
User-Agent: ININ-TsServer/4.0006.0017.364
Content-Length: 0
.?AVSIPResponseEntry@@ 17:43:54.8716133_0038 SIPEngine.Packets 0x1998
SIPSession::GetCustomHeaders : Found custom header=Call-ID, value=wlss-fcc72a0b-0ba58fac67af5f76@152.188.161.36
17:43:54.8741133_0018 SIPEngine.Processing 0x1998
SIPInboundIndication::SIPInboundIndication : Before
.?AVSIPInboundIndication@@ lrn=355812584 crn=0 user=0x000237ff
custom=[Call-ID/wlss-fcc72a0b-0ba58fac67af5f76@152.188.161.36,From/<sip:8005116880@74.80.226.163>;tag=e181103b,P-Asserted-Identity/UNAVAILABLE <sip:+18005116880@65.211.120.237>]
rUri=sip:1008171@10.21.46.102:5060 contact=sip:8005116880@172.31.154.77:5085 agent=
to=[]/[sip:1008171@garfield.infocisionprod.globalipcom.com:5060]
from=[]/[sip:8005116880@74.80.226.163:5060]
asserted identity=[UNAVAILABLE]/[sip:+18005116880@65.211.120.237]
referred-by=[]/[sip:]
events=[refer]
allow="ACK", "BYE", "CANCEL", "INVITE", "OPTIONS", "REFER", "SUBSCRIBE"
route_list="sip:8005116880@172.31.154.77:5085;sipappsessionid=app-1tym8ppll31n9", "sip:10.21.4.125:5060;lr"
dialog={call-id=wlss-fcc72a0b-0ba58fac67af5f76@152.188.161.36, to-tag=ch4cnjq, from-tag=e181103b}
media list=[Media Type=0, Address=172.31.154.196, Port=20300, Port Count=1
Payload=[0/G.711 mu-law]
direction=0, Attributes=[rtpmap=[0 PCMU/8000/1]], Fax Attributes=[]]
full body=true 17:43:54.8741133_0029 SIPEngine.Processing 0x19c4
SIPEngineWorkerThread::dispatch : assigning crn=2402653098 to callID=wlss-fcc72a0b-0ba58fac67af5f76@152.188.161.36
17:43:54.8791133_0081 SIPEngine.Processing 0x19d0
SIPUDPHandlerIO::issue_msg_write : S#145407: (P#26641b)*200$->INV$(P#266415) - udp xmit 10.21.46.102:5060 -> 10.21.4.125:5060 [739] msg=
SIP/2.0 200 OK
To: <sip:1008171@garfield.infocisionprod.globalipcom.com>;tag=ch4cnjq
From: <sip:8005116880@74.80.226.163>;tag=e181103b
Via: SIP/2.0/UDP 10.21.4.125:5060;branch=z9hG4bKb3725ac4b6877f55dc8292388, SIP/2.0/UDP 172.31.154.77:5085;branch=z9hG4bKrjpn7a108gsg4rtvffg0.1
CSeq: 1 INVITE
Call-ID: wlss-fcc72a0b-0ba58fac67af5f76@152.188.161.36
Record-Route: <sip:10.21.4.125:5060;lr;transport=udp>
Contact: <sip:1008171@10.21.46.102:5060>
User-Agent: ININ-TsServer/4.0006.0017.364
x-inin-crn: 2402653098;loc=GFH;ms=SVRGFHMED05
Content-Type: application/sdp
Content-Length: 144
v=0
o=ININ 30287897 30287899 IN IP4 10.21.46.102
s=Interaction
c=IN IP4 199.76.37.170
t=0 0
m=audio 26566 RTP/AVP 0
a=rtpmap:0 PCMU/8000
.?AVSIPRetriedResponseEntry@@ 17:43:54.9341133_0133 SIPEngine.Packets 0x1998
SIPHandlerIO::submit_recvd_message : *?ACK(P#26641c) - udp recv 10.21.46.102:5060 <- 10.21.4.125:5060 (retried-request) msg=
ACK sip:1008171@10.21.46.102:5060 SIP/2.0
Via: SIP/2.0/UDP 10.21.4.125:5060;branch=z9hG4bK31f954e2f9a30e9b707b49824, SIP/2.0/UDP 172.31.154.77:5085;branch=z9hG4bK0c746930cob51cro7lr0.1
To: <sip:1008171@garfield.infocisionprod.globalipcom.com>;tag=ch4cnjq
CSeq: 1 ACK
Content-Length: 0
Call-ID: wlss-fcc72a0b-0ba58fac67af5f76@152.188.161.36
Max-Forwards: 68
From: <sip:8005116880@74.80.226.163>;tag=e181103b
Record-Route: <sip:10.21.4.125:5060;lr;transport=udp> 17:43:55.1366133_0005 SIPEngine.Packets 0x27bc
SIPRequestInstance::SIPRequestInstance : inbound-leg: SIPCallLeg {
to/remote: <sip:8005116880@74.80.226.163>;tag=e181103b
from/local: <sip:1008171@garfield.infocisionprod.globalipcom.com>;tag=ch4cnjq
callID: wlss-fcc72a0b-0ba58fac67af5f76@152.188.161.36}
17:43:55.1366133_0023 SIPEngine.Processing 0x18cc
SIPSession::updateDestination : callID=wlss-fcc72a0b-0ba58fac67af5f76@152.188.161.36, old destination=10.21.4.125:5060
new destination=SIPViaUrl { host: "10.21.4.125" port: "5060" ttl: "" maddr: "" received: "" rport: "" branch: "z9hG4bK31f954e2f9a30e9b707b49824" transport: "udp" hidden: "false" generic-param { } } 17:43:55.1366133_0036 SIPEngine.Processing 0x1998
SIPSession::GetCustomHeaders : Found custom header=Call-ID, value=wlss-fcc72a0b-0ba58fac67af5f76@152.188.161.36
17:43:55.1366133_0041 SIPEngine.Processing 0x1998
SIPAnswerConfirmation::SIPAnswerConfirmation : Before
.?AVSIPAnswerConfirmation@@ lrn=355812584 crn=2402653098 user=0x00000000
error=eSipError=0 (No error)dialog={call-id=wlss-fcc72a0b-0ba58fac67af5f76@152.188.161.36, to-tag=e181103b, from-tag=ch4cnjq} 17:43:55.1366133_0047 SIPEngine.Processing 0x19d0
SIPHandlerIO::submit_recvd_message : ?BYE(P#266ce2) - udp recv 10.21.46.102:5060 <- 10.21.4.125:5060 (retried-request) msg=
BYE sip:1008171@10.21.46.102:5060 SIP/2.0
Via: SIP/2.0/UDP 10.21.4.125:5060;branch=z9hG4bK4f1cbaee50b8545b8ed9fd756, SIP/2.0/UDP 172.31.154.77:5085;branch=z9hG4bK0c746930cob51cro7lr0cd0000010.1
To: <sip:1008171@garfield.infocisionprod.globalipcom.com>;tag=ch4cnjq
CSeq: 2 BYE
Content-Length: 0
Call-ID: wlss-fcc72a0b-0ba58fac67af5f76@152.188.161.36
Max-Forwards: 68
From: <sip:8005116880@74.80.226.163>;tag=e181103b
Record-Route: <sip:10.21.4.125:5060;lr;transport=udp> 17:46:14.3541133_0103 SIPEngine.Packets 0x27bc
SIPRequestInstance::SIPRequestInstance : inbound-leg: SIPCallLeg {
to/remote: <sip:8005116880@74.80.226.163>;tag=e181103b
from/local: <sip:1008171@garfield.infocisionprod.globalipcom.com>;tag=ch4cnjq
callID: wlss-fcc72a0b-0ba58fac67af5f76@152.188.161.36}
17:46:14.3541133_0193 SIPEngine.Processing 0x18cc
SIPSession::updateDestination : callID=wlss-fcc72a0b-0ba58fac67af5f76@152.188.161.36, old destination=10.21.4.125:5060
new destination=SIPViaUrl { host: "10.21.4.125" port: "5060" ttl: "" maddr: "" received: "" rport: "" branch: "z9hG4bK4f1cbaee50b8545b8ed9fd756" transport: "udp" hidden: "false" generic-param { } } 17:46:14.3566133_0024 SIPEngine.Processing 0x1998
SIPUDPHandlerIO::issue_msg_write : S#145407: (P#266ce4)200->BYE(P#266ce2) - udp xmit 10.21.46.102:5060 -> 10.21.4.125:5060 [545] msg=
SIP/2.0 200 OK
To: <sip:1008171@garfield.infocisionprod.globalipcom.com>;tag=ch4cnjq
From: <sip:8005116880@74.80.226.163>;tag=e181103b
Via: SIP/2.0/UDP 10.21.4.125:5060;branch=z9hG4bK4f1cbaee50b8545b8ed9fd756, SIP/2.0/UDP 172.31.154.77:5085;branch=z9hG4bK0c746930cob51cro7lr0cd0000010.1
CSeq: 2 BYE
Call-ID: wlss-fcc72a0b-0ba58fac67af5f76@152.188.161.36
Record-Route: <sip:10.21.4.125:5060;lr;transport=udp>
Contact: <sip:1008171@10.21.46.102:5060>
User-Agent: ININ-TsServer/4.0006.0017.364
x-inin-crn: 2402653098
Content-Length: 0
.?AVSIPResponseEntry@@ 17:46:14.3566133_0061 SIPEngine.Packets 0x1998
SIPEngineWorkerThread::dispatch : Before [
.?AVSIPDisconnectIndication@@ lrn=355812584 crn=2402653098 user=0x00000000 code=1 reason=BYE reasonHdr= [] uui=[] dialog={call-id=wlss-fcc72a0b-0ba58fac67af5f76@152.188.161.36, to-tag=, from-tag=}]
17:46:14.3566133_0073 SIPEngine.Processing 0x19d0