pjsip / pjproject

PJSIP project
http://www.pjsip.org
GNU General Public License v2.0
2.03k stars 772 forks source link

TCP transmission corrupted #2342

Closed jchavanton closed 1 year ago

jchavanton commented 4 years ago

Describe the bug When receiving a 407 over TCP pjsip, the ACK sent by pjsip is corrupted and mixed the next INVITE Maybe some synchronization issue is taking place.

To Reproduce Steps to reproduce the behavior: Reproduced only in voip_patrol (a test application using pjsua2)

I will troubleshoot it further, but I wanted to report it here to see if I could get any insight.

Logs/Screenshots It is always the ACK that is facing the problem, here we can see that this blog is sent in one chunk and is overlapping at least 2 messages.

2020/03/11 16:35:39.914776 112.15.96.70:41533 -> 116.15.91.124:5060
ACK sip:+12012271232@sip.sipdomain.com;transport=tcp SIP/2.0
Via: SIP/2.0/TCP 112.15.96.70:3456;rport;branch=z9hG4bKPjAdtpUlfpai5xv4n2inr0KkroIDLpS9TG;alias
Max-Forwards: 70
From: sip:+15144009500@customer-mock.xyz;tag=LvIv94oFW.UDfCtNtTKkO93W.P9LSfOX
To: sip:+12012271232@sip.sipdomain.com;tag=bf8638324618dc61059d4c604476fea1.bb6d
Call-ID: aXi-10AOXRgvOigH98HPvYWCO2gO1ktC
CSeq: 10021 ACK
Content-Length:  0

INVITE sip:+12012271232@sip.sipdomain.com;transport=tcp SIP/2.0
Via: SIP/2.0/TCP 112.15.96.70:3456;rport;branch=z9hG4bKPj4tHlNqYReRoNkf6L59pEs.7ccJWxwimu;alias
Max-Forwards: 70
From: sip:+15144009500@customer-mock.xyz;tag=LvIv94oFW.UDfCtNtTKkO93W.P9LSfOX
To: sip:+12012271232@sip.sipdomain.com
Contact: <sip:+15144009500@112.15.96.70:41533;transport=TCP;ob>
Call-ID: aXi-10AOXRgvOigH98HPvYWCO2gO1ktC
CSeq: 10022 INVITE
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Supported: replaces, 100rel, timer, norefersub
Session-Expires: 1800
Min-SE: 90
Proxy-Authorization: Digest username="367613170", realm="sip.sipdomain.com", nonce="XmkUh15pE1vBV+MCRz4jgE5MCfERV7Kc", uri="sip:+12012271232@sip.sipdomain.com;transport=tcp", response="9ef2d66729d924bafa21
2057e9cb7a", cnonce="dqQzKJHQPBRdHu4NEHDYDC4xIdVvkP1M", qop=auth, nc=00000001
Content-Type: application/sdp
Content-Length:   340

v=0
o=- 3792933339 3792933339 IN IP4 112.15.96.70
s=pjmedia
b=AS:84
t=0 0
ACK sip:+12012271232@sip.sipdomain.com;transport=tcp SIP/2.0
Via: SIP/2.0/TCP 112.15.96.70:3456;rport;branch=z9hG4bKPjAdtpUlfpai5xv4n2inr0KkroIDLpS9TG;alias
Max-Forwards: 70
From: sip:+15144009500@customer-mock.xyz;tag=LvIv94oFW.UDfCtNtTKkO93W.P9LSfOX
To: sip:+12012271232@sip.sipdomain.com;tag=bf8638324618dc61059d4c604476fea1.bb6d
Call-ID: aXi-10AOXRgvOigH98HPvYWCO2gO1ktC
CSeq: 10021 ACK
Content-Length:  0

INVITE sip:+12012271232@sip.sipdomain.com;transport=tcp SIP/2.0
Via: SIP/2.0/TCP 112.15.96.70:3456;rport;branch=z9hG4bKPj4tHlNqYReRoNkf6L59pEs.7ccJWxwimu;alias
Max-Forwards: 70
From: sip:+15144009500@customer-mock.xyz;tag=LvIv94oFW.UDfCtNtTKkO93W.P9LSfOX
To: sip:+12012271232@sip.sipdomain.com
Contact: <sip:+15144009500@112.15.96.70:41533;transport=TCP;ob>
Call-ID: aXi-10AOXRgvOigH98HPvYWCO2gO1ktC
CSeq: 10022 INVITE
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Supported: replaces, 100rel, timer, norefersub
Session-Expires: 1800
Min-SE: 90
Proxy-Authorization: Digest username="367613170", realm="sip.sipdomain.com", nonce="XmkUh15pE1vBV+MCRz4jgE5MCfERV7Kc", uri="sip:+12012271232@sip.sipdomain.com;transport=tcp", response="9ef2d66729d924bafa21
2057e9cb7a", cnonce="dqQzKJHQPBRdHu4NEHDYDC4xIdVvkP1M", qop=auth, nc=00000001
Content-Type: application/sdp
Content-Length:   340

v=0
o=- 3792933339 3792933339 IN IP4 112.15.96.70
s=pjmedia
b=AS:84
t=0 0
a=X-nat:0
m=audio 4000 RTP/AVP 8 0 120
c=IN IP4 112.15.96.70
b=TIAS:64000
a=rtcp:4001 IN IP4 112.15.96.70
a=sendrecv
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:120 telephone-event/8000
a=fmtp:120 0-16
a=ssrc:1108232200 cname:1ec12c5272aacaf1

pjsua logs are not reporting any problem

16:35:39.618         sip_endpoint.c  .Module "mod-pjsua-log" registered
16:35:39.618         sip_endpoint.c  .Module "mod-tsx-layer" registered
16:35:39.618         sip_endpoint.c  .Module "mod-stateful-util" registered
16:35:39.618         sip_endpoint.c  .Module "mod-ua" registered
16:35:39.618         sip_endpoint.c  .Module "mod-100rel" registered
16:35:39.618         sip_endpoint.c  .Module "mod-pjsua" registered
16:35:39.619         sip_endpoint.c  .Module "mod-invite" registered
16:35:39.624             alsa_dev.c  ..ALSA driver found 0 devices
16:35:39.624             alsa_dev.c  ..ALSA initialized
16:35:39.633                  pjlib  ..select() I/O Queue created (0x1a2f438)
16:35:39.633           conference.c  ..Creating conference bridge with 514 ports
16:35:39.633           Master/sound  ..Using delay buffer with WSOLA.
16:35:39.640         sip_endpoint.c  .Module "mod-evsub" registered
16:35:39.640         sip_endpoint.c  .Module "mod-presence" registered
16:35:39.640                evsub.c  .Event pkg "presence" registered by mod-presence
16:35:39.640         sip_endpoint.c  .Module "mod-mwi" registered
16:35:39.640                evsub.c  .Event pkg "message-summary" registered by mod-mwi
16:35:39.640         sip_endpoint.c  .Module "mod-refer" registered
16:35:39.640                evsub.c  .Event pkg "refer" registered by mod-refer
16:35:39.640         sip_endpoint.c  .Module "mod-pjsua-pres" registered
16:35:39.640         sip_endpoint.c  .Module "mod-pjsua-im" registered
16:35:39.640         sip_endpoint.c  .Module "mod-pjsua-options" registered
16:35:39.640           pjsua_core.c  .1 SIP worker threads created
16:35:39.640           pjsua_core.c  .pjsua version 2.10-dev for Linux-4.4.0.134/x86_64/glibc-2.23 initialized
16:35:39.640           pjsua_core.c  .PJSUA state changed: CREATED --> INIT
16:35:39.647           pjsua_core.c  SIP UDP socket reachable at 112.15.96.70:3456
16:35:39.647           udp0x1ad15c0  SIP UDP transport started, published address is 112.15.96.70:3456
16:35:39.653             tcptp:3456  SIP TCP listener ready for incoming connections at 112.15.96.70:3456
16:35:39.659             tlstp:3457  SIP TLS listener is ready for incoming connections at 112.15.96.70:3457
16:35:39.659            pjsua_aud.c  Setting null sound device..
16:35:39.659            pjsua_aud.c  .Opening null sound device..
16:35:39.659           pjsua_core.c  PJSUA state changed: INIT --> STARTING
16:35:39.659         sip_endpoint.c  .Module "mod-unsolicited-mwi" registered
16:35:39.659           pjsua_core.c  .PJSUA state changed: STARTING --> RUNNING
16:35:39.659            pjsua_acc.c  Adding account: id=sip:default
16:35:39.659            pjsua_acc.c  .Account sip:default added with id 0
16:35:39.660            pjsua_acc.c  Adding account: id=sip:367613170@sip.sipdomain.com
16:35:39.660            pjsua_acc.c  .Account sip:367613170@sip.sipdomain.com added with id 1
16:35:39.660            pjsua_acc.c  .Acc 1: setting registration..
16:35:39.660               endpoint  ..Request msg REGISTER/cseq=15115 (tdta0x1adc5e8) created.
16:35:39.660           tsx0x1ade5a8  ...Transaction created for Request msg REGISTER/cseq=15116 (tdta0x1adc5e8)
16:35:39.660           tsx0x1ade5a8  ..Sending Request msg REGISTER/cseq=15116 (tdta0x1adc5e8) in state Null
16:35:39.660          sip_resolve.c  ...DNS resolver not available, target 'sip.sipdomain.com:0' type=TCP will be resolved with getaddrinfo()
16:35:39.662          sip_resolve.c  ...Target 'sip.sipdomain.com:0' type=TCP resolved to '116.15.91.124:5060' type=TCP (TCP transport)
16:35:39.662          tcpc0x1adf588  ...TCP client transport created
16:35:39.662          tcpc0x1adf588  ...TCP transport 112.15.96.70:41533 is connecting to 116.15.91.124:5060...
16:35:39.662           pjsua_core.c  ...TX 542 bytes Request msg REGISTER/cseq=15116 (tdta0x1adc5e8) to TCP 116.15.91.124:5060:
REGISTER sip:sip.sipdomain.com SIP/2.0
Via: SIP/2.0/TCP 112.15.96.70:3456;rport;branch=z9hG4bKPjt9Coqihz-M7iZJ8LACDjeQMRf6aIjLYI;alias
Max-Forwards: 70
From: <sip:367613170@sip.sipdomain.com>;tag=15KNHAt-tK7OczsFWhNW5v9kUiFTOrx8
To: <sip:367613170@sip.sipdomain.com>
Call-ID: do-2ekz0ioHGb8D4-H8bSlr-zsoADEfX
CSeq: 15116 REGISTER
User-Agent: <voip_patrol>
Contact: <sip:367613170@112.15.96.70:3456;ob>
Expires: 300
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Content-Length:  0

--end msg--
16:35:39.662           tsx0x1ade5a8  ...State changed from Null to Calling, event=TX_MSG
16:35:39.662            pjsua_acc.c  ..Acc 1: Registration sent
16:35:39.662            pjsua_acc.c  Adding account: id=sip:+15144009500@customer-mock.xyz;transport=tcp
16:35:39.662            pjsua_acc.c  .Account sip:+15144009500@customer-mock.xyz;transport=tcp added with id 2
16:35:39.662           pjsua_call.c  Making call with acc #2 to sip:+12012271232@sip.sipdomain.com;transport=tcp
16:35:39.663           dlg0x1ae4518  .UAC dialog created
16:35:39.664            pjsua_acc.c  .Unable to use source local TCP socket address for Contact: gethostbyname() has returned error (PJ_ERESOLVE)
16:35:39.664           dlg0x1ae4518  ..Session count inc to 2 by mod-pjsua
16:35:39.664          pjsua_media.c  .Call 0: initializing media..
16:35:39.669          pjsua_media.c  ..RTP socket reachable at 112.15.96.70:4000
16:35:39.669          pjsua_media.c  ..RTCP socket reachable at 112.15.96.70:4001
16:35:39.669          srtp0x1ae8910  ..SRTP keying SDES created
16:35:39.669          pjsua_media.c  ..Media index 0 selected for audio call 0
16:35:39.669          pjsua_media.c  ..Call 0: media transport initialization complete: Success
16:35:39.669           dlg0x1ae4518  ..Session count dec to 2 by mod-pjsua
16:35:39.669           dlg0x1ae4518  .Module mod-invite added as dialog usage, data=0x1aeaaf8
16:35:39.669           dlg0x1ae4518  ..Session count inc to 4 by mod-invite
16:35:39.669           dlg0x1ae4518  .Module mod-100rel added as dialog usage, data=0x1ae5470
16:35:39.669           dlg0x1ae4518  .100rel module attached
16:35:39.669           inv0x1ae4518  .UAC invite session created for dialog dlg0x1ae4518
16:35:39.669               endpoint  .Request msg INVITE/cseq=10022 (tdta0x1aec7f8) created.
16:35:39.669           inv0x1ae4518  ..Sending Request msg INVITE/cseq=10022 (tdta0x1aec7f8)
16:35:39.669           dlg0x1ae4518  ...Sending Request msg INVITE/cseq=10022 (tdta0x1aec7f8)
16:35:39.669           tsx0x1aef768  ....Transaction created for Request msg INVITE/cseq=10021 (tdta0x1aec7f8)
16:35:39.669           tsx0x1aef768  ...Sending Request msg INVITE/cseq=10021 (tdta0x1aec7f8) in state Null
16:35:39.669          sip_resolve.c  ....DNS resolver not available, target 'sip.sipdomain.com:0' type=TCP will be resolved with getaddrinfo()
16:35:39.670          sip_resolve.c  ....Target 'sip.sipdomain.com:0' type=TCP resolved to '116.15.91.124:5060' type=TCP (TCP transport)
16:35:39.670           pjsua_core.c  ....TX 1004 bytes Request msg INVITE/cseq=10021 (tdta0x1aec7f8) to TCP 116.15.91.124:5060:
INVITE sip:+12012271232@sip.sipdomain.com;transport=tcp SIP/2.0
Via: SIP/2.0/TCP 112.15.96.70:3456;rport;branch=z9hG4bKPjAdtpUlfpai5xv4n2inr0KkroIDLpS9TG;alias
Max-Forwards: 70
From: sip:+15144009500@customer-mock.xyz;tag=LvIv94oFW.UDfCtNtTKkO93W.P9LSfOX
To: sip:+12012271232@sip.sipdomain.com
Contact: <sip:+15144009500@112.15.96.70:41533;transport=TCP;ob>
Call-ID: aXi-10AOXRgvOigH98HPvYWCO2gO1ktC
CSeq: 10021 INVITE
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Supported: replaces, 100rel, timer, norefersub
Session-Expires: 1800
Min-SE: 90
Content-Type: application/sdp
Content-Length:   340

v=0
o=- 3792933339 3792933339 IN IP4 112.15.96.70
s=pjmedia
b=AS:84
t=0 0
a=X-nat:0
m=audio 4000 RTP/AVP 8 0 120
c=IN IP4 112.15.96.70
b=TIAS:64000
a=rtcp:4001 IN IP4 112.15.96.70
a=sendrecv
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:120 telephone-event/8000
a=fmtp:120 0-16
a=ssrc:1108232200 cname:1ec12c5272aacaf1

--end msg--
16:35:39.670           tsx0x1aef768  ....State changed from Null to Calling, event=TX_MSG
16:35:39.670           dlg0x1ae4518  .....Transaction tsx0x1aef768 state changed to Calling
16:35:39.729          tcpc0x1adf588 !TCP transport 112.15.96.70:41533 is connected to 116.15.91.124:5060
16:35:39.843         sip_endpoint.c  Processing incoming message: Response msg 401/REGISTER/cseq=15116 (rdata0x1adf868)
16:35:39.843           pjsua_core.c  .RX 500 bytes Response msg 401/REGISTER/cseq=15116 (rdata0x1adf868) from TCP 116.15.91.124:5060:
SIP/2.0 401 Unauthorized
Via: SIP/2.0/TCP 112.15.96.70:3456;received=112.15.96.70;rport=41533;branch=z9hG4bKPjt9Coqihz-M7iZJ8LACDjeQMRf6aIjLYI;alias
From: <sip:367613170@sip.sipdomain.com>;tag=15KNHAt-tK7OczsFWhNW5v9kUiFTOrx8
To: <sip:367613170@sip.sipdomain.com>;tag=bf8638324618dc61059d4c604476fea1.bb6d
Call-ID: do-2ekz0ioHGb8D4-H8bSlr-zsoADEfX
CSeq: 15116 REGISTER
WWW-Authenticate: Digest realm="sip.sipdomain.com", nonce="XmkUh15pE1s/iyDAtTOP3iNqLpSOW95s", qop="auth"
Content-Length: 0

--end msg--
16:35:39.843           tsx0x1ade5a8  .Incoming Response msg 401/REGISTER/cseq=15116 (rdata0x1adf868) in state Calling
16:35:39.843           tsx0x1ade5a8  ..State changed from Calling to Completed, event=RX_MSG
16:35:39.843            pjsua_acc.c  ....IP address change detected for account 1 (112.15.96.70:3456 --> 112.15.96.70:41533). Updating registration (using method 4)
16:35:39.843      tsx0x7f89dc0023a8  ....Transaction created for Request msg REGISTER/cseq=15117 (tdta0x1adc5e8)
16:35:39.843      tsx0x7f89dc0023a8  ...Sending Request msg REGISTER/cseq=15117 (tdta0x1adc5e8) in state Null
16:35:39.843               endpoint  ....Request msg REGISTER/cseq=15117 (tdta0x1adc5e8): skipping target resolution because address is already set
16:35:39.843           pjsua_core.c  ....TX 810 bytes Request msg REGISTER/cseq=15117 (tdta0x1adc5e8) to TCP 116.15.91.124:5060:
REGISTER sip:sip.sipdomain.com SIP/2.0
Via: SIP/2.0/TCP 112.15.96.70:41533;rport;branch=z9hG4bKPjH.UoXcuGlfxI19WkxxYxCPlFot3W2ugW;alias
Max-Forwards: 70
From: <sip:367613170@sip.sipdomain.com>;tag=15KNHAt-tK7OczsFWhNW5v9kUiFTOrx8
To: <sip:367613170@sip.sipdomain.com>
Call-ID: do-2ekz0ioHGb8D4-H8bSlr-zsoADEfX
CSeq: 15117 REGISTER
User-Agent: <voip_patrol>
Contact: <sip:367613170@112.15.96.70:41533;transport=TCP;ob>
Expires: 300
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Authorization: Digest username="367613170", realm="sip.sipdomain.com", nonce="XmkUh15pE1s/iyDAtTOP3iNqLpSOW95s", uri="sip:sip.sipdomain.com", response="59c85a3066506dc7c8d5abb7696dfda2", cnonce="TDyKfuT8TVfm3aOZokuom0.Fn.2utMHz", qop=auth, nc=00000001
Content-Length:  0

--end msg--
16:35:39.843      tsx0x7f89dc0023a8  ....State changed from Null to Calling, event=TX_MSG
16:35:39.843           tsx0x1ade5a8  Timeout timer event
16:35:39.843           tsx0x1ade5a8  .State changed from Completed to Terminated, event=TIMER
16:35:39.843           tsx0x1ade5a8  Timeout timer event
16:35:39.843           tsx0x1ade5a8  .State changed from Terminated to Destroyed, event=TIMER
16:35:39.843           tsx0x1ade5a8  Transaction destroyed!
16:35:39.863         sip_endpoint.c  Processing incoming message: Response msg 100/INVITE/cseq=10021 (rdata0x1adf868)
16:35:39.863           pjsua_core.c  .RX 348 bytes Response msg 100/INVITE/cseq=10021 (rdata0x1adf868) from TCP 116.15.91.124:5060:
SIP/2.0 100 Trying
Via: SIP/2.0/TCP 112.15.96.70:3456;rport=41533;branch=z9hG4bKPjAdtpUlfpai5xv4n2inr0KkroIDLpS9TG;alias;received=112.15.96.70
From: sip:+15144009500@customer-mock.xyz;tag=LvIv94oFW.UDfCtNtTKkO93W.P9LSfOX
To: sip:+12012271232@sip.sipdomain.com
Call-ID: aXi-10AOXRgvOigH98HPvYWCO2gO1ktC
CSeq: 10021 INVITE
Content-Length: 0

--end msg--
16:35:39.863           tsx0x1aef768  .Incoming Response msg 100/INVITE/cseq=10021 (rdata0x1adf868) in state Calling
16:35:39.863           tsx0x1aef768  ..State changed from Calling to Proceeding, event=RX_MSG
16:35:39.863           dlg0x1ae4518  ...Received Response msg 100/INVITE/cseq=10021 (rdata0x1adf868)
16:35:39.863           dlg0x1ae4518  ...Transaction tsx0x1aef768 state changed to Proceeding
16:35:39.914         sip_endpoint.c  Processing incoming message: Response msg 407/INVITE/cseq=10021 (rdata0x1adf868)
16:35:39.914           pjsua_core.c  .RX 521 bytes Response msg 407/INVITE/cseq=10021 (rdata0x1adf868) from TCP 116.15.91.124:5060:
SIP/2.0 407 Proxy Authentication Required
Via: SIP/2.0/TCP 112.15.96.70:3456;received=112.15.96.70;rport=41533;branch=z9hG4bKPjAdtpUlfpai5xv4n2inr0KkroIDLpS9TG;alias
From: sip:+15144009500@customer-mock.xyz;tag=LvIv94oFW.UDfCtNtTKkO93W.P9LSfOX
To: sip:+12012271232@sip.sipdomain.com;tag=bf8638324618dc61059d4c604476fea1.bb6d
Call-ID: aXi-10AOXRgvOigH98HPvYWCO2gO1ktC
CSeq: 10021 INVITE
Proxy-Authenticate: Digest realm="sip.sipdomain.com", nonce="XmkUh15pE1vBV+MCRz4jgE5MCfERV7Kc", qop="auth"
Content-Length: 0

--end msg--
16:35:39.914           tsx0x1aef768  .Incoming Response msg 407/INVITE/cseq=10021 (rdata0x1adf868) in state Proceeding
16:35:39.914               endpoint  ..Request msg ACK/cseq=10021 (tdta0x7f89dc002fd8) created.
16:35:39.914           pjsua_core.c  ..TX 420 bytes Request msg ACK/cseq=10021 (tdta0x7f89dc002fd8) to TCP 116.15.91.124:5060:
ACK sip:+12012271232@sip.sipdomain.com;transport=tcp SIP/2.0
Via: SIP/2.0/TCP 112.15.96.70:3456;rport;branch=z9hG4bKPjAdtpUlfpai5xv4n2inr0KkroIDLpS9TG;alias
Max-Forwards: 70
From: sip:+15144009500@customer-mock.xyz;tag=LvIv94oFW.UDfCtNtTKkO93W.P9LSfOX
To: sip:+12012271232@sip.sipdomain.com;tag=bf8638324618dc61059d4c604476fea1.bb6d
Call-ID: aXi-10AOXRgvOigH98HPvYWCO2gO1ktC
CSeq: 10021 ACK
Content-Length:  0

--end msg--
16:35:39.914           tsx0x1aef768  ..State changed from Proceeding to Completed, event=RX_MSG
16:35:39.914           dlg0x1ae4518  ...Received Response msg 407/INVITE/cseq=10021 (rdata0x1adf868)
16:35:39.914           dlg0x1ae4518  ...Transaction tsx0x1aef768 state changed to Completed
16:35:39.914           inv0x1ae4518  .....Sending Request msg INVITE/cseq=10021 (tdta0x1aec7f8)
16:35:39.914           dlg0x1ae4518  ......Sending Request msg INVITE/cseq=10021 (tdta0x1aec7f8)
16:35:39.914      tsx0x7f89dc007508  .......Transaction created for Request msg INVITE/cseq=10022 (tdta0x1aec7f8)
16:35:39.914      tsx0x7f89dc007508  ......Sending Request msg INVITE/cseq=10022 (tdta0x1aec7f8) in state Null
16:35:39.914               endpoint  .......Request msg INVITE/cseq=10022 (tdta0x1aec7f8): skipping target resolution because address is already set
16:35:39.914           pjsua_core.c  .......TX 1289 bytes Request msg INVITE/cseq=10022 (tdta0x1aec7f8) to TCP 116.15.91.124:5060:
INVITE sip:+12012271232@sip.sipdomain.com;transport=tcp SIP/2.0
Via: SIP/2.0/TCP 112.15.96.70:3456;rport;branch=z9hG4bKPj4tHlNqYReRoNkf6L59pEs.7ccJWxwimu;alias
Max-Forwards: 70
From: sip:+15144009500@customer-mock.xyz;tag=LvIv94oFW.UDfCtNtTKkO93W.P9LSfOX
To: sip:+12012271232@sip.sipdomain.com
Contact: <sip:+15144009500@112.15.96.70:41533;transport=TCP;ob>
Call-ID: aXi-10AOXRgvOigH98HPvYWCO2gO1ktC
CSeq: 10022 INVITE
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Supported: replaces, 100rel, timer, norefersub
Session-Expires: 1800
Min-SE: 90
Proxy-Authorization: Digest username="367613170", realm="sip.sipdomain.com", nonce="XmkUh15pE1vBV+MCRz4jgE5MCfERV7Kc", uri="sip:+12012271232@sip.sipdomain.com;transport=tcp", response="9ef2d66729d924bafa21872057e9cb7a", cnonce="dqQzKJHQPBRdHu4NEHDYDC4xIdVvkP1M", qop=auth, nc=00000001
Content-Type: application/sdp
Content-Length:   340

v=0
o=- 3792933339 3792933339 IN IP4 112.15.96.70
s=pjmedia
b=AS:84
t=0 0
a=X-nat:0
m=audio 4000 RTP/AVP 8 0 120
c=IN IP4 112.15.96.70
b=TIAS:64000
a=rtcp:4001 IN IP4 112.15.96.70
a=sendrecv
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:120 telephone-event/8000
a=fmtp:120 0-16
a=ssrc:1108232200 cname:1ec12c5272aacaf1

--end msg--
16:35:39.914      tsx0x7f89dc007508  .......State changed from Null to Calling, event=TX_MSG
16:35:39.914           dlg0x1ae4518  ........Transaction tsx0x7f89dc007508 state changed to Calling
16:35:39.914           tsx0x1aef768  Timeout timer event
16:35:39.914           tsx0x1aef768  .State changed from Completed to Terminated, event=TIMER
16:35:39.914           dlg0x1ae4518  ..Transaction tsx0x1aef768 state changed to Terminated
16:35:39.914           tsx0x1aef768  Timeout timer event
16:35:39.914           tsx0x1aef768  .State changed from Terminated to Destroyed, event=TIMER
16:35:39.914     tdta0x7f89dc002fd8  ..Destroying txdata Request msg ACK/cseq=10021 (tdta0x7f89dc002fd8)
16:35:39.914           tsx0x1aef768  Transaction destroyed!
16:35:39.977         sip_endpoint.c  Processing incoming message: Response msg 200/REGISTER/cseq=15117 (rdata0x1adf868)
16:35:39.977           pjsua_core.c  .RX 510 bytes Response msg 200/REGISTER/cseq=15117 (rdata0x1adf868) from TCP 116.15.91.124:5060:
SIP/2.0 200 OK
Via: SIP/2.0/TCP 112.15.96.70:41533;received=112.15.96.70;rport=41533;branch=z9hG4bKPjH.UoXcuGlfxI19WkxxYxCPlFot3W2ugW;alias
From: <sip:367613170@sip.sipdomain.com>;tag=15KNHAt-tK7OczsFWhNW5v9kUiFTOrx8
To: <sip:367613170@sip.sipdomain.com>;tag=bf8638324618dc61059d4c604476fea1.bb6d
Call-ID: do-2ekz0ioHGb8D4-H8bSlr-zsoADEfX
CSeq: 15117 REGISTER
Contact: <sip:367613170@112.15.96.70:41533;transport=TCP;ob>;q=1;expires=265;received="sip:112.15.96.70:41533;transport=tcp"
Content-Length: 0

--end msg--
16:35:39.977      tsx0x7f89dc0023a8  .Incoming Response msg 200/REGISTER/cseq=15117 (rdata0x1adf868) in state Calling
16:35:39.977      tsx0x7f89dc0023a8  ..State changed from Calling to Completed, event=RX_MSG
16:35:39.977            pjsua_acc.c  ....SIP outbound status for acc 1 is not active
16:35:39.977            pjsua_acc.c  ....sip:367613170@sip.sipdomain.com: registration success, status=200 (OK), will re-register in 265 seconds
16:35:39.977      tsx0x7f89dc0023a8  Timeout timer event
16:35:39.977      tsx0x7f89dc0023a8  .State changed from Completed to Terminated, event=TIMER
16:35:39.977      tsx0x7f89dc0023a8  Timeout timer event
16:35:39.977      tsx0x7f89dc0023a8  .State changed from Terminated to Destroyed, event=TIMER
16:35:39.977          tdta0x1adc5e8  ..Destroying txdata Request msg REGISTER/cseq=15117 (tdta0x1adc5e8)
16:35:39.977      tsx0x7f89dc0023a8  Transaction destroyed!
16:35:40.034         sip_endpoint.c  Processing incoming message: Response msg 100/INVITE/cseq=10022 (rdata0x1adf868)
16:35:40.034           pjsua_core.c  .RX 348 bytes Response msg 100/INVITE/cseq=10022 (rdata0x1adf868) from TCP 116.15.91.124:5060:
SIP/2.0 100 Trying
Via: SIP/2.0/TCP 112.15.96.70:3456;rport=41533;branch=z9hG4bKPj4tHlNqYReRoNkf6L59pEs.7ccJWxwimu;alias;received=112.15.96.70
From: sip:+15144009500@customer-mock.xyz;tag=LvIv94oFW.UDfCtNtTKkO93W.P9LSfOX
To: sip:+12012271232@sip.sipdomain.com
Call-ID: aXi-10AOXRgvOigH98HPvYWCO2gO1ktC
CSeq: 10022 INVITE
Content-Length: 0

--end msg--
16:35:40.034      tsx0x7f89dc007508  .Incoming Response msg 100/INVITE/cseq=10022 (rdata0x1adf868) in state Calling
16:35:40.034      tsx0x7f89dc007508  ..State changed from Calling to Proceeding, event=RX_MSG
16:35:40.034           dlg0x1ae4518  ...Received Response msg 100/INVITE/cseq=10022 (rdata0x1adf868)
16:35:40.034           dlg0x1ae4518  ...Transaction tsx0x7f89dc007508 state changed to Proceeding
16:35:40.660            pjsua_aud.c  Closing sound device after idle for 1 second(s)
16:35:40.660            pjsua_aud.c  .Closing null sound device..
16:35:40.789         sip_endpoint.c  Processing incoming message: Request msg INVITE/cseq=189913 (rdata0x1adf868)
16:35:40.789           pjsua_core.c  .RX 1170 bytes Request msg INVITE/cseq=189913 (rdata0x1adf868) from TCP 116.15.91.124:5060:
INVITE sip:12012271232@112.15.96.70:41533;transport=TCP SIP/2.0
Record-Route: <sip:116.15.91.124;transport=tcp;r2=on;lr>
Record-Route: <sip:116.15.91.124;r2=on;lr>
From: "MONTREAL     QC" <sip:+15144009500@fl.gg>;tag=gK0027fbf1
Max-Forwards: 66
Record-Route: <sip:216.115.69.132;lr>
To: <sip:+12012271232@fl.gg>
Via: SIP/2.0/TCP 116.15.91.124;branch=z9hG4bK3c62.aad3b76071608423b63106cbdb614472.0
Via: SIP/2.0/UDP 54.71.6.127:5060;branch=z9hG4bK3c62.863eac06ffc83e58df9f8c6659893c5a.0
Via: SIP/2.0/UDP 216.115.69.132;branch=z9hG4bK3c62.e57ec3aa9a48bcf0e659a3828ab9bddd.0
Via: SIP/2.0/UDP 207.223.78.224:5060;branch=z9hG4bK00B9e3a518dd880e5e9
Call-ID: 157290149_83336707@207.223.78.224
CSeq: 189913 INVITE
Contact: <sip:+15144009500@207.223.78.224:5060>
Session-Expires: 21600
Min-SE: 90
Content-Length:   225
Content-Type: application/sdp
Supported: timer
P-Asserted-Identity: "MONTREAL     QC" <sip:+15144009500@fl.gg>

v=0
o=- 791193 474537 IN IP4 207.223.78.60
s=-
c=IN IP4 207.223.78.60
t=0 0
m=audio 8120 RTP/AVP 0 8 18 101
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=maxptime:20

--end msg--
16:35:40.789           pjsua_call.c  .Incoming Request msg INVITE/cseq=189913 (rdata0x1adf868)
16:35:40.789      tsx0x7f89dc00b038  ...Transaction created for Request msg INVITE/cseq=189913 (rdata0x1adf868)
16:35:40.789      tsx0x7f89dc00b038  ..Incoming Request msg INVITE/cseq=189913 (rdata0x1adf868) in state Null
16:35:40.789      tsx0x7f89dc00b038  ...State changed from Null to Trying, event=RX_MSG
16:35:40.789      dlg0x7f89dc0023a8  ....Transaction tsx0x7f89dc00b038 state changed to Trying
16:35:40.789      dlg0x7f89dc0023a8  ..UAS dialog created
16:35:40.789      dlg0x7f89dc0023a8  ..Module mod-invite added as dialog usage, data=0x7f89dc00bde8
16:35:40.789      dlg0x7f89dc0023a8  ...Session count inc to 3 by mod-invite
16:35:40.789      inv0x7f89dc0023a8  ..UAS invite session created for dialog dlg0x7f89dc0023a8
16:35:40.789      dlg0x7f89dc0023a8  ...Session count inc to 3 by mod-pjsua
16:35:40.789          pjsua_media.c  ..Call 1: initializing media..
16:35:40.796          pjsua_media.c  ...RTP socket reachable at 112.15.96.70:4002
16:35:40.796          pjsua_media.c  ...RTCP socket reachable at 112.15.96.70:4003
16:35:40.796     srtp0x7f89dc0146a0  ...SRTP keying SDES created
16:35:40.796          pjsua_media.c  ...Media index 0 selected for audio call 1
16:35:40.796          pjsua_media.c  ...Call 1: media transport initialization complete: Success
16:35:40.796           pjsua_call.c  ...Answering call 1: code=200
16:35:40.796           pjsua_call.c  ....Pending answering call 1 upon completion of media transport
16:35:40.796      dlg0x7f89dc0023a8  ...Session count dec to 3 by mod-pjsua
16:35:40.796           pjsua_call.c  ..Call 1: remote NAT type is 0 (Unknown)
16:35:40.796               endpoint  ...Response msg 100/INVITE/cseq=189913 (tdta0x7f89dc018e38) created
16:35:40.796      dlg0x7f89dc0023a8  ...Initial answer Response msg 100/INVITE/cseq=189913 (tdta0x7f89dc018e38)
16:35:40.796      inv0x7f89dc0023a8  ...Sending Response msg 100/INVITE/cseq=189913 (tdta0x7f89dc018e38)
16:35:40.796      dlg0x7f89dc0023a8  ....Sending Response msg 100/INVITE/cseq=189913 (tdta0x7f89dc018e38)
16:35:40.796      tsx0x7f89dc00b038  ....Sending Response msg 100/INVITE/cseq=189913 (tdta0x7f89dc018e38) in state Trying
16:35:40.796           pjsua_core.c  .....TX 704 bytes Response msg 100/INVITE/cseq=189913 (tdta0x7f89dc018e38) to TCP 116.15.91.124:5060:
SIP/2.0 100 Trying
Via: SIP/2.0/TCP 116.15.91.124;received=116.15.91.124;branch=z9hG4bK3c62.aad3b76071608423b63106cbdb614472.0
Via: SIP/2.0/UDP 54.71.6.127:5060;branch=z9hG4bK3c62.863eac06ffc83e58df9f8c6659893c5a.0
Via: SIP/2.0/UDP 216.115.69.132;branch=z9hG4bK3c62.e57ec3aa9a48bcf0e659a3828ab9bddd.0
Via: SIP/2.0/UDP 207.223.78.224:5060;branch=z9hG4bK00B9e3a518dd880e5e9
Record-Route: <sip:116.15.91.124;transport=tcp;lr;r2=on>
Record-Route: <sip:116.15.91.124;lr;r2=on>
Record-Route: <sip:216.115.69.132;lr>
Call-ID: 157290149_83336707@207.223.78.224
From: "MONTREAL     QC" <sip:+15144009500@fl.gg>;tag=gK0027fbf1
To: <sip:+12012271232@fl.gg>
CSeq: 189913 INVITE
Content-Length:  0

--end msg--
16:35:40.796      tsx0x7f89dc00b038  .....State changed from Trying to Proceeding, event=TX_MSG
16:35:40.796      dlg0x7f89dc0023a8  ......Transaction tsx0x7f89dc00b038 state changed to Proceeding
16:35:40.796           pjsua_call.c  ..Answering call 1: code=200
16:35:40.796        sip_transport.c  ....Tx data Response msg 100/INVITE/cseq=189913 (tdta0x7f89dc01d018) cloned
16:35:40.796      inv0x7f89dc0023a8  ....SDP negotiation done: Success
16:35:40.796           pjsua_call.c  .....Call 1: remote NAT type is 0 (Unknown)
16:35:40.796          pjsua_media.c  .....Call 1: updating media..
16:35:40.796          pjsua_media.c  .......Media stream call01:0 is destroyed
16:35:40.796            pjsua_aud.c  ......Audio channel update..
16:35:40.796                  rtp.c  .......pjmedia_rtp_session_init: ses=0x7f89dc024900, default_pt=0, ssrc=0x5638f242
16:35:40.796                  rtp.c  .......pjmedia_rtp_session_init: ses=0x7f89dc024f80, default_pt=0, ssrc=0x5638f242
16:35:40.796               stream.c  .......Stream strm0x7f89dc021a98 created
16:35:40.796     strm0x7f89dc021a98  .......Encoder stream started
16:35:40.796     strm0x7f89dc021a98  .......Decoder stream started
16:35:40.796             resample.c  .......resample created: high qualiy, large filter, in/out rate=8000/16000
16:35:40.796             resample.c  .......resample created: high qualiy, large filter, in/out rate=16000/8000
16:35:40.796          pjsua_media.c  ......Audio updated, stream #0: PCMU (sendrecv)
16:35:40.796      inv0x7f89dc0023a8  ....Sending Response msg 200/INVITE/cseq=189913 (tdta0x7f89dc01d018)
16:35:40.796      dlg0x7f89dc0023a8  .....Sending Response msg 200/INVITE/cseq=189913 (tdta0x7f89dc01d018)
16:35:40.796      tsx0x7f89dc00b038  .....Sending Response msg 200/INVITE/cseq=189913 (tdta0x7f89dc01d018) in state Proceeding
16:35:40.796     tdta0x7f89dc018e38  ......Destroying txdata Response msg 100/INVITE/cseq=189913 (tdta0x7f89dc018e38)
16:35:40.796           pjsua_core.c  ......TX 1276 bytes Response msg 200/INVITE/cseq=189913 (tdta0x7f89dc01d018) to TCP 116.15.91.124:5060:
SIP/2.0 200 COCO
Via: SIP/2.0/TCP 116.15.91.124;received=116.15.91.124;branch=z9hG4bK3c62.aad3b76071608423b63106cbdb614472.0
Via: SIP/2.0/UDP 54.71.6.127:5060;branch=z9hG4bK3c62.863eac06ffc83e58df9f8c6659893c5a.0
Via: SIP/2.0/UDP 216.115.69.132;branch=z9hG4bK3c62.e57ec3aa9a48bcf0e659a3828ab9bddd.0
Via: SIP/2.0/UDP 207.223.78.224:5060;branch=z9hG4bK00B9e3a518dd880e5e9
Record-Route: <sip:116.15.91.124;transport=tcp;lr;r2=on>
Record-Route: <sip:116.15.91.124;lr;r2=on>
Record-Route: <sip:216.115.69.132;lr>
Call-ID: 157290149_83336707@207.223.78.224
From: "MONTREAL     QC" <sip:+15144009500@fl.gg>;tag=gK0027fbf1
To: <sip:+12012271232@fl.gg>;tag=UCcbf2NEbY2Ucl41UrOWdQIEUA.s5iBj
CSeq: 189913 INVITE
Contact: <sip:112.15.96.70:3456;transport=TCP>
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Supported: replaces, 100rel, norefersub
Content-Type: application/sdp
Content-Length:   316

v=0
o=- 3792933340 3792933341 IN IP4 112.15.96.70
s=pjmedia
b=AS:84
t=0 0
a=X-nat:0
m=audio 4002 RTP/AVP 0 101
c=IN IP4 112.15.96.70
b=TIAS:64000
a=rtcp:4003 IN IP4 112.15.96.70
a=sendrecv
a=rtpmap:0 PCMU/8000
a=ssrc:1446572610 cname:5893e9c17a7e2bfb
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16

--end msg--
16:35:40.796      tsx0x7f89dc00b038  ......State changed from Proceeding to Completed, event=TX_MSG
16:35:40.796      dlg0x7f89dc0023a8  .......Transaction tsx0x7f89dc00b038 state changed to Completed
16:35:41.134     strm0x7f89dc021a98 !RTP status: badpt=0, badssrc=0, dup=0, outorder=0, probation=-1, restart=0
16:35:41.287         sip_endpoint.c !Processing incoming message: Response msg 200/INVITE/cseq=10022 (rdata0x1adf868)
16:35:41.287           pjsua_core.c  .RX 822 bytes Response msg 200/INVITE/cseq=10022 (rdata0x1adf868) from TCP 116.15.91.124:5060:
SIP/2.0 200 OK
From: sip:+15144009500@customer-mock.xyz;tag=LvIv94oFW.UDfCtNtTKkO93W.P9LSfOX
To: sip:+12012271232@sip.sipdomain.com;tag=gK0b9e9eeb
Via: SIP/2.0/TCP 112.15.96.70:3456;received=112.15.96.70;rport=41533;branch=z9hG4bKPj4tHlNqYReRoNkf6L59pEs.7ccJWxwimu;alias
Call-ID: aXi-10AOXRgvOigH98HPvYWCO2gO1ktC
CSeq: 10022 INVITE
Record-Route: <sip:216.115.69.133:5060;lr>
Record-Route: <sip:116.15.91.124:5060;r2=on;lr>
Record-Route: <sip:116.15.91.124:5060;transport=tcp;r2=on;lr>
Contact: <sip:+12012271232@23.29.31.84:5060>
Session-Expires: 1800;refresher=uas
Content-Length:  170
Content-Type: application/sdp
Supported: timer

v=0
o=- 12518 8872 IN IP4 23.29.31.91
s=-
c=IN IP4 23.29.31.91
t=0 0
m=audio 17288 RTP/AVP 8 120
a=rtpmap:120 telephone-event/8000
a=fmtp:120 0-15
a=maxptime:20

--end msg--
16:35:41.287      tsx0x7f89dc007508  .Incoming Response msg 200/INVITE/cseq=10022 (rdata0x1adf868) in state Proceeding
16:35:41.287      tsx0x7f89dc007508  ..State changed from Proceeding to Terminated, event=RX_MSG
16:35:41.287           dlg0x1ae4518  ...Received Response msg 200/INVITE/cseq=10022 (rdata0x1adf868)
16:35:41.287           dlg0x1ae4518  ....Route-set updated
16:35:41.287           dlg0x1ae4518  ....Route-set frozen
16:35:41.287           dlg0x1ae4518  ...Transaction tsx0x7f89dc007508 state changed to Terminated
16:35:41.287           inv0x1ae4518  ....Got SDP answer in Response msg 200/INVITE/cseq=10022 (rdata0x1adf868)
16:35:41.287           inv0x1ae4518  ....SDP negotiation done: Success
16:35:41.287           pjsua_call.c  .....Call 0: remote NAT type is 0 (Unknown)
16:35:41.287          pjsua_media.c  .....Call 0: updating media..
16:35:41.287          pjsua_media.c  .......Media stream call00:0 is destroyed
16:35:41.287            pjsua_aud.c  ......Audio channel update..
16:35:41.287                  rtp.c  .......pjmedia_rtp_session_init: ses=0x7f89dc02a7f0, default_pt=8, ssrc=0x420e4808
16:35:41.287                  rtp.c  .......pjmedia_rtp_session_init: ses=0x7f89dc01c900, default_pt=8, ssrc=0x420e4808
16:35:41.287               stream.c  .......Stream strm0x7f89dc028168 created
16:35:41.287     strm0x7f89dc028168  .......Encoder stream started
16:35:41.287     strm0x7f89dc028168  .......Decoder stream started
16:35:41.287             resample.c  .......resample created: high qualiy, large filter, in/out rate=8000/16000
16:35:41.287             resample.c  .......resample created: high qualiy, large filter, in/out rate=16000/8000
16:35:41.287          pjsua_media.c  ......Audio updated, stream #0: PCMA (sendrecv)
16:35:41.288           inv0x1ae4518  ....Received Response msg 200/INVITE/cseq=10022 (rdata0x1adf868), sending ACK
16:35:41.288               endpoint  ....Request msg ACK/cseq=10022 (tdta0x7f89dc02daf8) created.
16:35:41.288           dlg0x1ae4518  .....Sending Request msg ACK/cseq=10022 (tdta0x7f89dc02daf8)
16:35:41.288          sip_resolve.c  .....Target '116.15.91.124:5060' type=TCP resolved to '116.15.91.124:5060' type=TCP (TCP transport)
16:35:41.288           pjsua_core.c  .....TX 515 bytes Request msg ACK/cseq=10022 (tdta0x7f89dc02daf8) to TCP 116.15.91.124:5060:
ACK sip:+12012271232@23.29.31.84:5060 SIP/2.0
Via: SIP/2.0/TCP 112.15.96.70:3456;rport;branch=z9hG4bKPjJ4uX6XK7xD-xhGudJrJ1TIzBfUP6rhGU;alias
Max-Forwards: 70
From: sip:+15144009500@customer-mock.xyz;tag=LvIv94oFW.UDfCtNtTKkO93W.P9LSfOX
To: sip:+12012271232@sip.sipdomain.com;tag=gK0b9e9eeb
Call-ID: aXi-10AOXRgvOigH98HPvYWCO2gO1ktC
CSeq: 10022 ACK
Route: <sip:116.15.91.124:5060;transport=tcp;lr;r2=on>
Route: <sip:116.15.91.124:5060;lr;r2=on>
Route: <sip:216.115.69.133:5060;lr>
Content-Length:  0

--end msg--
16:35:41.288            pjsua_aud.c  .....Creating file player: /git/voip_patrol/voice_ref_files/reference_8000_12s.wav..
16:35:41.288            pjsua_aud.c  ......Unable to open file for playback: Not found (PJ_ENOTFOUND) [status=70006]
16:35:41.288      tsx0x7f89dc007508  Timeout timer event
16:35:41.288      tsx0x7f89dc007508  .State changed from Terminated to Destroyed, event=TIMER
16:35:41.288      tsx0x7f89dc007508  Transaction destroyed!
16:35:41.291     strm0x7f89dc028168 !RTP status: badpt=-1, badssrc=0, dup=0, outorder=0, probation=0, restart=0
16:35:41.291     strm0x7f89dc028168  Bad RTP pt 0 (expecting 8)
16:35:41.291     strm0x7f89dc028168  RTP status: badpt=-1, badssrc=0, dup=0, outorder=0, probation=0, restart=0
16:35:41.291     strm0x7f89dc028168  Bad RTP pt 0 (expecting 8)
16:35:41.291     strm0x7f89dc028168  RTP status: badpt=-1, badssrc=0, dup=0, outorder=0, probation=0, restart=0
16:35:41.291     strm0x7f89dc028168  Bad RTP pt 0 (expecting 8)
16:35:41.297      tsx0x7f89dc00b038 !Retransmit timer event
16:35:41.297      tsx0x7f89dc00b038  .Retransmiting Response msg 200/INVITE/cseq=189913 (tdta0x7f89dc01d018), count=0, restart?=1
16:35:41.297           pjsua_core.c  .TX 1276 bytes Response msg 200/INVITE/cseq=189913 (tdta0x7f89dc01d018) to TCP 116.15.91.124:5060:
SIP/2.0 200 COCO
Via: SIP/2.0/TCP 116.15.91.124;received=116.15.91.124;branch=z9hG4bK3c62.aad3b76071608423b63106cbdb614472.0
Via: SIP/2.0/UDP 54.71.6.127:5060;branch=z9hG4bK3c62.863eac06ffc83e58df9f8c6659893c5a.0
Via: SIP/2.0/UDP 216.115.69.132;branch=z9hG4bK3c62.e57ec3aa9a48bcf0e659a3828ab9bddd.0
Via: SIP/2.0/UDP 207.223.78.224:5060;branch=z9hG4bK00B9e3a518dd880e5e9
Record-Route: <sip:116.15.91.124;transport=tcp;lr;r2=on>
Record-Route: <sip:116.15.91.124;lr;r2=on>
Record-Route: <sip:216.115.69.132;lr>
Call-ID: 157290149_83336707@207.223.78.224
From: "MONTREAL     QC" <sip:+15144009500@fl.gg>;tag=gK0027fbf1
To: <sip:+12012271232@fl.gg>;tag=UCcbf2NEbY2Ucl41UrOWdQIEUA.s5iBj
CSeq: 189913 INVITE
Contact: <sip:112.15.96.70:3456;transport=TCP>
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Supported: replaces, 100rel, norefersub
Content-Type: application/sdp
Content-Length:   316

v=0
o=- 3792933340 3792933341 IN IP4 112.15.96.70
s=pjmedia
b=AS:84
t=0 0
a=X-nat:0
m=audio 4002 RTP/AVP 0 101
c=IN IP4 112.15.96.70
b=TIAS:64000
a=rtcp:4003 IN IP4 112.15.96.70
a=sendrecv
a=rtpmap:0 PCMU/8000
a=ssrc:1446572610 cname:5893e9c17a7e2bfb
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16

--end msg--
16:35:41.311     strm0x7f89dc028168 !RTP status: badpt=-1, badssrc=0, dup=0, outorder=0, probation=0, restart=0
16:35:41.311     strm0x7f89dc028168  Bad RTP pt 0 (expecting 8)
16:35:41.331     strm0x7f89dc028168  RTP status: badpt=-1, badssrc=0, dup=0, outorder=0, probation=0, restart=0
16:35:41.331     strm0x7f89dc028168  Bad RTP pt 0 (expecting 8)
16:35:41.351     strm0x7f89dc028168  RTP status: badpt=-1, badssrc=0, dup=0, outorder=0, probation=0, restart=0
16:35:41.351     strm0x7f89dc028168  Bad RTP pt 0 (expecting 8)
16:35:41.370         sip_endpoint.c !Processing incoming message: Request msg INVITE/cseq=32166 (rdata0x1adf868)
16:35:41.370           pjsua_core.c  .RX 1083 bytes Request msg INVITE/cseq=32166 (rdata0x1adf868) from TCP 116.15.91.124:5060:
INVITE sip:+15144009500@112.15.96.70:41533;transport=TCP;ob SIP/2.0
Record-Route: <sip:116.15.91.124;transport=tcp;r2=on;lr;did=9da2.c9a2>
Record-Route: <sip:116.15.91.124;r2=on;lr;did=9da2.c9a2>
Record-Route: <sip:216.115.69.133;lr>
From: sip:+12012271232@sip.sipdomain.com;tag=gK0b9e9eeb
To: sip:+15144009500@customer-mock.xyz;tag=LvIv94oFW.UDfCtNtTKkO93W.P9LSfOX
Via: SIP/2.0/TCP 116.15.91.124;branch=z9hG4bK7b7f.98d2c9a3f8e48d3d724812f1c2fe42ca.0
Via: SIP/2.0/UDP 216.115.69.133;branch=z9hG4bK7b7f.525cf19c64a2339ef3da729994adb9e6.0
Via: SIP/2.0/UDP 23.29.31.84:5060;branch=z9hG4bK0bB2dd532583de4890e
Call-ID: aXi-10AOXRgvOigH98HPvYWCO2gO1ktC
CSeq: 32166 INVITE
Max-Forwards: 68
Contact: <sip:+12012271232@23.29.31.84:5060>
Session-Expires: 1800;refresher=uac
Min-SE: 90
Content-Length:  217
Content-Type: application/sdp
Supported: timer

v=0
o=- 12518 8873 IN IP4 23.29.31.91
s=-
c=IN IP4 23.29.31.91
t=0 0
m=audio 17288 RTP/AVP 0 18 120
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:120 telephone-event/8000
a=fmtp:120 0-15
a=maxptime:20

--end msg--
16:35:41.370           dlg0x1ae4518  .Received Request msg INVITE/cseq=32166 (rdata0x1adf868)
16:35:41.370      tsx0x7f89dc007508  ...Transaction created for Request msg INVITE/cseq=32166 (rdata0x1adf868)
16:35:41.370      tsx0x7f89dc007508  ..Incoming Request msg INVITE/cseq=32166 (rdata0x1adf868) in state Null
16:35:41.370      tsx0x7f89dc007508  ...State changed from Null to Trying, event=RX_MSG
16:35:41.370           dlg0x1ae4518  ....Transaction tsx0x7f89dc007508 state changed to Trying
16:35:41.370           inv0x1ae4518  .....Got SDP offer in Request msg INVITE/cseq=32166 (rdata0x1adf868)
16:35:41.370           pjsua_call.c  .....Call 0: received updated media offer
16:35:41.370          pjsua_media.c  ......Call 0: re-initializing media..
16:35:41.370          pjsua_media.c  .......Media index 0 selected for audio call 0
16:35:41.370          pjsua_media.c  .......Call 0: media transport initialization complete: Success
16:35:41.370               endpoint  .....Response msg 200/INVITE/cseq=32166 (tdta0x7f89dc034f18) created
16:35:41.370           inv0x1ae4518  .....SDP negotiation done: Success
16:35:41.370           pjsua_call.c  ......Call 0: remote NAT type is 0 (Unknown)
16:35:41.370          pjsua_media.c  ......Call 0: updating media..
16:35:41.370     strm0x7f89dc028168  ........JB summary:
  size=0/eff=0 prefetch=0 level=0
  delay (min/max/avg/dev)=0/0/0/0 ms
  burst (min/max/avg/dev)=0/0/0/0 frames
  lost=0 discard=0 empty=0
16:35:41.370          pjsua_media.c  ........Media stream call00:0 is destroyed
16:35:41.370            pjsua_aud.c  .......Audio channel update..
16:35:41.370                  rtp.c  ........pjmedia_rtp_session_init: ses=0x7f89dc02a7f0, default_pt=0, ssrc=0x420e4808
16:35:41.370                  rtp.c  ........pjmedia_rtp_session_init: ses=0x7f89dc02ae70, default_pt=0, ssrc=0x420e4808
16:35:41.370               stream.c  ........Stream strm0x7f89dc028168 created
16:35:41.370     strm0x7f89dc028168  ........Encoder stream started
16:35:41.370     strm0x7f89dc028168  ........Decoder stream started
16:35:41.370             resample.c  ........resample created: high qualiy, large filter, in/out rate=8000/16000
16:35:41.370             resample.c  ........resample created: high qualiy, large filter, in/out rate=16000/8000
16:35:41.370          pjsua_media.c  .......Audio updated, stream #0: PCMU (sendrecv)
16:35:41.370           inv0x1ae4518  ......Sending Response msg 200/INVITE/cseq=32166 (tdta0x7f89dc034f18)
16:35:41.370           dlg0x1ae4518  .......Sending Response msg 200/INVITE/cseq=32166 (tdta0x7f89dc034f18)
16:35:41.370      tsx0x7f89dc007508  .......Sending Response msg 200/INVITE/cseq=32166 (tdta0x7f89dc034f18) in state Trying
16:35:41.370           pjsua_core.c  ........TX 1291 bytes Response msg 200/INVITE/cseq=32166 (tdta0x7f89dc034f18) to TCP 116.15.91.124:5060:
SIP/2.0 200 OK
Via: SIP/2.0/TCP 116.15.91.124;received=116.15.91.124;branch=z9hG4bK7b7f.98d2c9a3f8e48d3d724812f1c2fe42ca.0
Via: SIP/2.0/UDP 216.115.69.133;branch=z9hG4bK7b7f.525cf19c64a2339ef3da729994adb9e6.0
Via: SIP/2.0/UDP 23.29.31.84:5060;branch=z9hG4bK0bB2dd532583de4890e
Record-Route: <sip:116.15.91.124;transport=tcp;lr;r2=on;did=9da2.c9a2>
Record-Route: <sip:116.15.91.124;lr;r2=on;did=9da2.c9a2>
Record-Route: <sip:216.115.69.133;lr>
Call-ID: aXi-10AOXRgvOigH98HPvYWCO2gO1ktC
From: <sip:+12012271232@sip.sipdomain.com>;tag=gK0b9e9eeb
To: <sip:+15144009500@customer-mock.xyz>;tag=LvIv94oFW.UDfCtNtTKkO93W.P9LSfOX
CSeq: 32166 INVITE
Session-Expires: 1800;refresher=uac
Require: timer
Contact: <sip:+15144009500@112.15.96.70:41533;transport=TCP;ob>
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Supported: replaces, 100rel, timer, norefersub
Content-Type: application/sdp
Content-Length:   316

v=0
o=- 3792933339 3792933340 IN IP4 112.15.96.70
s=pjmedia
b=AS:84
t=0 0
a=X-nat:0
m=audio 4000 RTP/AVP 0 120
c=IN IP4 112.15.96.70
b=TIAS:64000
a=rtcp:4001 IN IP4 112.15.96.70
a=sendrecv
a=rtpmap:0 PCMU/8000
a=rtpmap:120 telephone-event/8000
a=fmtp:120 0-16
a=ssrc:1108232200 cname:1ec12c5272aacaf1

--end msg--
16:35:41.370      tsx0x7f89dc007508  ........State changed from Trying to Completed, event=TX_MSG
16:35:41.370           dlg0x1ae4518  .........Transaction tsx0x7f89dc007508 state changed to Completed
16:35:41.371     strm0x7f89dc028168 !RTP status: badpt=0, badssrc=0, dup=0, outorder=0, probation=-1, restart=0
16:35:41.539         sip_endpoint.c !Processing incoming message: Request msg ACK/cseq=32166 (rdata0x1adf868)
16:35:41.539           pjsua_core.c  .RX 717 bytes Request msg ACK/cseq=32166 (rdata0x1adf868) from TCP 116.15.91.124:5060:
ACK sip:+15144009500@112.15.96.70:41533;transport=TCP;ob SIP/2.0
Record-Route: <sip:116.15.91.124;transport=tcp;r2=on;lr;did=9da2.c9a2>
Record-Route: <sip:116.15.91.124;r2=on;lr;did=9da2.c9a2>
Record-Route: <sip:216.115.69.133;lr>
From: <sip:+12012271232@sip.sipdomain.com>;tag=gK0b9e9eeb
To: <sip:+15144009500@customer-mock.xyz>;tag=LvIv94oFW.UDfCtNtTKkO93W.P9LSfOX
Via: SIP/2.0/TCP 116.15.91.124;branch=z9hG4bK7b7f.bb321c277f30e41cd629d0ba00de72b4.0
Via: SIP/2.0/UDP 216.115.69.133;branch=z9hG4bK7b7f.b17ee2953e07c7fcc4a39a4d914536dd.0
Via: SIP/2.0/UDP 23.29.31.84:5060;branch=z9hG4bK0bB2dd72b7a3de4890e
Call-ID: aXi-10AOXRgvOigH98HPvYWCO2gO1ktC
CSeq: 32166 ACK
Max-Forwards: 68
Content-Length: 0

--end msg--
16:35:41.539           dlg0x1ae4518  .Received Request msg ACK/cseq=32166 (rdata0x1adf868)
16:35:41.539      tsx0x7f89dc007508  ..Request to terminate transaction
16:35:41.539      tsx0x7f89dc007508  ...State changed from Completed to Terminated, event=USER
16:35:41.539           dlg0x1ae4518  ....Transaction tsx0x7f89dc007508 state changed to Terminated
16:35:41.539      tsx0x7f89dc007508  Timeout timer event
16:35:41.539      tsx0x7f89dc007508  .State changed from Terminated to Destroyed, event=TIMER
16:35:41.539     tdta0x7f89dc034f18  ..Destroying txdata Response msg 200/INVITE/cseq=32166 (tdta0x7f89dc034f18)
16:35:41.539      tsx0x7f89dc007508  Transaction destroyed!
16:35:41.569     strm0x7f89dc028168 !RTP status: badpt=0, badssrc=0, dup=0, outorder=-1, probation=0, restart=0
16:35:41.589     strm0x7f89dc028168  RTP status: badpt=0, badssrc=0, dup=0, outorder=-1, probation=0, restart=0
16:35:41.609     strm0x7f89dc028168  RTP status: badpt=0, badssrc=0, dup=0, outorder=-1, probation=0, restart=0
16:35:41.629     strm0x7f89dc028168  RTP status: badpt=0, badssrc=0, dup=0, outorder=-1, probation=0, restart=0
16:35:41.649     strm0x7f89dc028168  RTP status: badpt=0, badssrc=0, dup=0, outorder=-1, probation=0, restart=0
16:35:41.669     strm0x7f89dc028168  RTP status: badpt=0, badssrc=0, dup=0, outorder=-1, probation=0, restart=0
16:35:41.689     strm0x7f89dc028168  RTP status: badpt=0, badssrc=0, dup=0, outorder=-1, probation=0, restart=0
16:35:41.709     strm0x7f89dc028168  RTP status: badpt=0, badssrc=0, dup=0, outorder=-1, probation=0, restart=0
16:35:41.729     strm0x7f89dc028168  RTP status: badpt=0, badssrc=0, dup=0, outorder=-1, probation=0, restart=0
16:35:41.749     strm0x7f89dc028168  RTP status: badpt=0, badssrc=0, dup=0, outorder=-1, probation=0, restart=0
16:35:41.769     strm0x7f89dc028168  RTP status: badpt=0, badssrc=0, dup=0, outorder=-1, probation=0, restart=0
16:35:41.789     strm0x7f89dc028168  RTP status: badpt=0, badssrc=0, dup=0, outorder=-1, probation=0, restart=0
16:35:41.809     strm0x7f89dc028168  RTP status: badpt=0, badssrc=0, dup=0, outorder=-1, probation=0, restart=0
16:35:41.829     strm0x7f89dc028168  RTP status: badpt=0, badssrc=0, dup=0, outorder=-1, probation=0, restart=0
16:35:41.849     strm0x7f89dc028168  RTP status: badpt=0, badssrc=0, dup=0, outorder=-1, probation=0, restart=0
16:35:41.869     strm0x7f89dc028168  RTP status: badpt=0, badssrc=0, dup=0, outorder=-1, probation=0, restart=0
16:35:41.889     strm0x7f89dc028168  RTP status: badpt=0, badssrc=0, dup=0, outorder=-1, probation=0, restart=0
16:35:41.909     strm0x7f89dc028168  RTP status: badpt=0, badssrc=0, dup=-1, outorder=0, probation=0, restart=0
16:35:42.034         sip_endpoint.c !Processing incoming message: Request msg OPTIONS/cseq=1 (rdata0x1adf868)
16:35:42.034           pjsua_core.c  .RX 640 bytes Request msg OPTIONS/cseq=1 (rdata0x1adf868) from TCP 116.15.91.124:5060:
OPTIONS sip:367613170@112.15.96.70:41533;transport=TCP;ob SIP/2.0
Max-Forwards: 20
Record-Route: <sip:116.15.91.124;transport=tcp;r2=on;lr>
Record-Route: <sip:116.15.91.124;r2=on;lr>
Via: SIP/2.0/TCP 116.15.91.124;branch=z9hG4bK0d52.bef69b6977e8cb4f73516781e9794ed5.0
Via: SIP/2.0/UDP 52.40.141.109:5060;branch=z9hG4bK6945521
Route: <sip:116.15.91.124;lr;received=sip:112.15.96.70:41533%3Btransport%3Dtcp>
From: sip:ping@invalid;tag=uloc-5e3e08d7-1a-9ac9aa7-a8e0dba6-d31b1789
To: sip:367613170@112.15.96.70:41533;transport=TCP;ob
Call-ID: cb1d2386-d6902f49-fd36661@0.0.0.0
CSeq: 1 OPTIONS
Content-Length: 0
Max-Forward: 10

--end msg--
16:35:42.034               endpoint  .Response msg 200/OPTIONS/cseq=1 (tdta0x7f89dc034f18) created
16:35:42.034           pjsua_core.c  .TX 920 bytes Response msg 200/OPTIONS/cseq=1 (tdta0x7f89dc034f18) to TCP 116.15.91.124:5060:
SIP/2.0 200 OK
Via: SIP/2.0/TCP 116.15.91.124;received=116.15.91.124;branch=z9hG4bK0d52.bef69b6977e8cb4f73516781e9794ed5.0
Via: SIP/2.0/UDP 52.40.141.109:5060;branch=z9hG4bK6945521
Record-Route: <sip:116.15.91.124;transport=tcp;lr;r2=on>
Record-Route: <sip:116.15.91.124;lr;r2=on>
Call-ID: cb1d2386-d6902f49-fd36661@0.0.0.0
From: <sip:ping@invalid>;tag=uloc-5e3e08d7-1a-9ac9aa7-a8e0dba6-d31b1789
To: <sip:367613170@112.15.96.70>;tag=z9hG4bK0d52.bef69b6977e8cb4f73516781e9794ed5.0;transport=TCP;ob
CSeq: 1 OPTIONS
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Accept: application/sdp, application/pidf+xml, application/xpidf+xml, application/simple-message-summary, message/sipfrag;version=2.0, application/im-iscomposing+xml, text/plain
Supported: replaces, 100rel, timer, norefersub
Allow-Events: presence, message-summary, refer
Content-Length:  0

--end msg--
16:35:42.034     tdta0x7f89dc034f18  .Destroying txdata Response msg 200/OPTIONS/cseq=1 (tdta0x7f89dc034f18)
16:35:42.296      tsx0x7f89dc00b038  Retransmit timer event
16:35:42.296      tsx0x7f89dc00b038  .Retransmiting Response msg 200/INVITE/cseq=189913 (tdta0x7f89dc01d018), count=1, restart?=1
16:35:42.296           pjsua_core.c  .TX 1276 bytes Response msg 200/INVITE/cseq=189913 (tdta0x7f89dc01d018) to TCP 116.15.91.124:5060:
SIP/2.0 200 COCO
Via: SIP/2.0/TCP 116.15.91.124;received=116.15.91.124;branch=z9hG4bK3c62.aad3b76071608423b63106cbdb614472.0
Via: SIP/2.0/UDP 54.71.6.127:5060;branch=z9hG4bK3c62.863eac06ffc83e58df9f8c6659893c5a.0
Via: SIP/2.0/UDP 216.115.69.132;branch=z9hG4bK3c62.e57ec3aa9a48bcf0e659a3828ab9bddd.0
Via: SIP/2.0/UDP 207.223.78.224:5060;branch=z9hG4bK00B9e3a518dd880e5e9
Record-Route: <sip:116.15.91.124;transport=tcp;lr;r2=on>
Record-Route: <sip:116.15.91.124;lr;r2=on>
Record-Route: <sip:216.115.69.132;lr>
Call-ID: 157290149_83336707@207.223.78.224
From: "MONTREAL     QC" <sip:+15144009500@fl.gg>;tag=gK0027fbf1
To: <sip:+12012271232@fl.gg>;tag=UCcbf2NEbY2Ucl41UrOWdQIEUA.s5iBj
CSeq: 189913 INVITE
Contact: <sip:112.15.96.70:3456;transport=TCP>
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Supported: replaces, 100rel, norefersub
Content-Type: application/sdp
Content-Length:   316

v=0
o=- 3792933340 3792933341 IN IP4 112.15.96.70
s=pjmedia
b=AS:84
t=0 0
a=X-nat:0
m=audio 4002 RTP/AVP 0 101
c=IN IP4 112.15.96.70
b=TIAS:64000
a=rtcp:4003 IN IP4 112.15.96.70
a=sendrecv
a=rtpmap:0 PCMU/8000
a=ssrc:1446572610 cname:5893e9c17a7e2bfb
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16

--end msg--
16:35:44.297      tsx0x7f89dc00b038  Retransmit timer event
16:35:44.297      tsx0x7f89dc00b038  .Retransmiting Response msg 200/INVITE/cseq=189913 (tdta0x7f89dc01d018), count=2, restart?=1
16:35:44.297           pjsua_core.c  .TX 1276 bytes Response msg 200/INVITE/cseq=189913 (tdta0x7f89dc01d018) to TCP 116.15.91.124:5060:
SIP/2.0 200 COCO
Via: SIP/2.0/TCP 116.15.91.124;received=116.15.91.124;branch=z9hG4bK3c62.aad3b76071608423b63106cbdb614472.0
Via: SIP/2.0/UDP 54.71.6.127:5060;branch=z9hG4bK3c62.863eac06ffc83e58df9f8c6659893c5a.0
Via: SIP/2.0/UDP 216.115.69.132;branch=z9hG4bK3c62.e57ec3aa9a48bcf0e659a3828ab9bddd.0
Via: SIP/2.0/UDP 207.223.78.224:5060;branch=z9hG4bK00B9e3a518dd880e5e9
Record-Route: <sip:116.15.91.124;transport=tcp;lr;r2=on>
Record-Route: <sip:116.15.91.124;lr;r2=on>
Record-Route: <sip:216.115.69.132;lr>
Call-ID: 157290149_83336707@207.223.78.224
From: "MONTREAL     QC" <sip:+15144009500@fl.gg>;tag=gK0027fbf1
To: <sip:+12012271232@fl.gg>;tag=UCcbf2NEbY2Ucl41UrOWdQIEUA.s5iBj
CSeq: 189913 INVITE
Contact: <sip:112.15.96.70:3456;transport=TCP>
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Supported: replaces, 100rel, norefersub
Content-Type: application/sdp
Content-Length:   316

v=0
o=- 3792933340 3792933341 IN IP4 112.15.96.70
s=pjmedia
b=AS:84
t=0 0
a=X-nat:0
m=audio 4002 RTP/AVP 0 101
c=IN IP4 112.15.96.70
b=TIAS:64000
a=rtcp:4003 IN IP4 112.15.96.70
a=sendrecv
a=rtpmap:0 PCMU/8000
a=ssrc:1446572610 cname:5893e9c17a7e2bfb
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16

--end msg--
16:35:48.296      tsx0x7f89dc00b038  Retransmit timer event
16:35:48.297      tsx0x7f89dc00b038  .Retransmiting Response msg 200/INVITE/cseq=189913 (tdta0x7f89dc01d018), count=3, restart?=1
16:35:48.297           pjsua_core.c  .TX 1276 bytes Response msg 200/INVITE/cseq=189913 (tdta0x7f89dc01d018) to TCP 116.15.91.124:5060:
SIP/2.0 200 COCO
Via: SIP/2.0/TCP 116.15.91.124;received=116.15.91.124;branch=z9hG4bK3c62.aad3b76071608423b63106cbdb614472.0
Via: SIP/2.0/UDP 54.71.6.127:5060;branch=z9hG4bK3c62.863eac06ffc83e58df9f8c6659893c5a.0
Via: SIP/2.0/UDP 216.115.69.132;branch=z9hG4bK3c62.e57ec3aa9a48bcf0e659a3828ab9bddd.0
Via: SIP/2.0/UDP 207.223.78.224:5060;branch=z9hG4bK00B9e3a518dd880e5e9
Record-Route: <sip:116.15.91.124;transport=tcp;lr;r2=on>
Record-Route: <sip:116.15.91.124;lr;r2=on>
Record-Route: <sip:216.115.69.132;lr>
Call-ID: 157290149_83336707@207.223.78.224
From: "MONTREAL     QC" <sip:+15144009500@fl.gg>;tag=gK0027fbf1
To: <sip:+12012271232@fl.gg>;tag=UCcbf2NEbY2Ucl41UrOWdQIEUA.s5iBj
CSeq: 189913 INVITE
Contact: <sip:112.15.96.70:3456;transport=TCP>
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Supported: replaces, 100rel, norefersub
Content-Type: application/sdp
Content-Length:   316

v=0
o=- 3792933340 3792933341 IN IP4 112.15.96.70
s=pjmedia
b=AS:84
t=0 0
a=X-nat:0
m=audio 4002 RTP/AVP 0 101
c=IN IP4 112.15.96.70
b=TIAS:64000
a=rtcp:4003 IN IP4 112.15.96.70
a=sendrecv
a=rtpmap:0 PCMU/8000
a=ssrc:1446572610 cname:5893e9c17a7e2bfb
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16

--end msg--
16:35:51.301           pjsua_call.c !Call 0 hanging up: code=0..
16:35:51.301               endpoint  ..Request msg BYE/cseq=10024 (tdta0x1ad7af8) created.
16:35:51.301           inv0x1ae4518  ..Sending Request msg BYE/cseq=10024 (tdta0x1ad7af8)
16:35:51.301           dlg0x1ae4518  ...Sending Request msg BYE/cseq=10024 (tdta0x1ad7af8)
16:35:51.301           tsx0x1aef768  ....Transaction created for Request msg BYE/cseq=10023 (tdta0x1ad7af8)
16:35:51.301           tsx0x1aef768  ...Sending Request msg BYE/cseq=10023 (tdta0x1ad7af8) in state Null
16:35:51.301          sip_resolve.c  ....Target '116.15.91.124:5060' type=TCP resolved to '116.15.91.124:5060' type=TCP (TCP transport)
16:35:51.301           pjsua_core.c  ....TX 515 bytes Request msg BYE/cseq=10023 (tdta0x1ad7af8) to TCP 116.15.91.124:5060:
BYE sip:+12012271232@23.29.31.84:5060 SIP/2.0
Via: SIP/2.0/TCP 112.15.96.70:3456;rport;branch=z9hG4bKPjWpWAxMoG7YurbQJK4KpaFIWR.h4gFA4k;alias
Max-Forwards: 70
From: sip:+15144009500@customer-mock.xyz;tag=LvIv94oFW.UDfCtNtTKkO93W.P9LSfOX
To: sip:+12012271232@sip.sipdomain.com;tag=gK0b9e9eeb
Call-ID: aXi-10AOXRgvOigH98HPvYWCO2gO1ktC
CSeq: 10023 BYE
Route: <sip:116.15.91.124:5060;transport=tcp;lr;r2=on>
Route: <sip:116.15.91.124:5060;lr;r2=on>
Route: <sip:216.115.69.133:5060;lr>
Content-Length:  0

--end msg--
16:35:51.301           tsx0x1aef768  ....State changed from Null to Calling, event=TX_MSG
16:35:51.301           dlg0x1ae4518  .....Transaction tsx0x1aef768 state changed to Calling
16:35:51.385         sip_endpoint.c !Processing incoming message: Response msg 200/BYE/cseq=10023 (rdata0x1adf868)
16:35:51.385           pjsua_core.c  .RX 514 bytes Response msg 200/BYE/cseq=10023 (rdata0x1adf868) from TCP 116.15.91.124:5060:
SIP/2.0 200 OK
From: sip:+15144009500@customer-mock.xyz;tag=LvIv94oFW.UDfCtNtTKkO93W.P9LSfOX
To: sip:+12012271232@sip.sipdomain.com;tag=gK0b9e9eeb
Via: SIP/2.0/TCP 112.15.96.70:3456;received=112.15.96.70;rport=41533;branch=z9hG4bKPjWpWAxMoG7YurbQJK4KpaFIWR.h4gFA4k;alias
Call-ID: aXi-10AOXRgvOigH98HPvYWCO2gO1ktC
CSeq: 10023 BYE
Record-Route: <sip:216.115.69.133:5060;lr>
Record-Route: <sip:116.15.91.124:5060;r2=on;lr>
Record-Route: <sip:116.15.91.124:5060;transport=tcp;r2=on;lr>
Content-Length: 0

--end msg--
16:35:51.385           tsx0x1aef768  .Incoming Response msg 200/BYE/cseq=10023 (rdata0x1adf868) in state Calling
16:35:51.385           tsx0x1aef768  ..State changed from Calling to Completed, event=RX_MSG
16:35:51.385           dlg0x1ae4518  ...Received Response msg 200/BYE/cseq=10023 (rdata0x1adf868)
16:35:51.385           dlg0x1ae4518  ...Transaction tsx0x1aef768 state changed to Completed
16:35:51.385          pjsua_media.c  .....Call 0: deinitializing media..
16:35:51.385     strm0x7f89dc028168  .......JB summary:
  size=50/eff=50 prefetch=0 level=0
  delay (min/max/avg/dev)=0/0/0/0 ms
  burst (min/max/avg/dev)=0/0/0/0 frames
  lost=0 discard=950 empty=0
16:35:51.385          pjsua_media.c  .......Media stream call00:0 is destroyed
16:35:51.385     tdta0x7f89dc02daf8  ....Destroying txdata Request msg ACK/cseq=10022 (tdta0x7f89dc02daf8)
16:35:51.385          tdta0x1aec7f8  ....Destroying txdata Request msg INVITE/cseq=10022 (tdta0x1aec7f8)
16:35:51.385           dlg0x1ae4518  .....Session count dec to 1 by mod-invite
16:35:51.385           tsx0x1aef768  Timeout timer event
16:35:51.385           tsx0x1aef768  .State changed from Completed to Terminated, event=TIMER
16:35:51.385           dlg0x1ae4518  ..Transaction tsx0x1aef768 state changed to Terminated
16:35:51.385           dlg0x1ae4518  ...Dialog destroyed!
16:35:51.385           tsx0x1aef768  Timeout timer event
16:35:51.385           tsx0x1aef768  .State changed from Terminated to Destroyed, event=TIMER
16:35:51.385          tdta0x1ad7af8  ..Destroying txdata Request msg BYE/cseq=10023 (tdta0x1ad7af8)
16:35:51.385           tsx0x1aef768  Transaction destroyed!
16:35:51.518     strm0x7f89dc021a98 !Received RTCP BYE, reason: -
16:35:52.297      tsx0x7f89dc00b038 !Retransmit timer event
16:35:52.297      tsx0x7f89dc00b038  .Retransmiting Response msg 200/INVITE/cseq=189913 (tdta0x7f89dc01d018), count=4, restart?=1
16:35:52.297           pjsua_core.c  .TX 1276 bytes Response msg 200/INVITE/cseq=189913 (tdta0x7f89dc01d018) to TCP 116.15.91.124:5060:
SIP/2.0 200 COCO
Via: SIP/2.0/TCP 116.15.91.124;received=116.15.91.124;branch=z9hG4bK3c62.aad3b76071608423b63106cbdb614472.0
Via: SIP/2.0/UDP 54.71.6.127:5060;branch=z9hG4bK3c62.863eac06ffc83e58df9f8c6659893c5a.0
Via: SIP/2.0/UDP 216.115.69.132;branch=z9hG4bK3c62.e57ec3aa9a48bcf0e659a3828ab9bddd.0
Via: SIP/2.0/UDP 207.223.78.224:5060;branch=z9hG4bK00B9e3a518dd880e5e9
Record-Route: <sip:116.15.91.124;transport=tcp;lr;r2=on>
Record-Route: <sip:116.15.91.124;lr;r2=on>
Record-Route: <sip:216.115.69.132;lr>
Call-ID: 157290149_83336707@207.223.78.224
From: "MONTREAL     QC" <sip:+15144009500@fl.gg>;tag=gK0027fbf1
To: <sip:+12012271232@fl.gg>;tag=UCcbf2NEbY2Ucl41UrOWdQIEUA.s5iBj
CSeq: 189913 INVITE
Contact: <sip:112.15.96.70:3456;transport=TCP>
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Supported: replaces, 100rel, norefersub
Content-Type: application/sdp
Content-Length:   316

v=0
o=- 3792933340 3792933341 IN IP4 112.15.96.70
s=pjmedia
b=AS:84
t=0 0
a=X-nat:0
m=audio 4002 RTP/AVP 0 101
c=IN IP4 112.15.96.70
b=TIAS:64000
a=rtcp:4003 IN IP4 112.15.96.70
a=sendrecv
a=rtpmap:0 PCMU/8000
a=ssrc:1446572610 cname:5893e9c17a7e2bfb
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16

--end msg--
16:35:56.297      tsx0x7f89dc00b038  Retransmit timer event
16:35:56.297      tsx0x7f89dc00b038  .Retransmiting Response msg 200/INVITE/cseq=189913 (tdta0x7f89dc01d018), count=5, restart?=1
16:35:56.297           pjsua_core.c  .TX 1276 bytes Response msg 200/INVITE/cseq=189913 (tdta0x7f89dc01d018) to TCP 116.15.91.124:5060:
SIP/2.0 200 COCO
Via: SIP/2.0/TCP 116.15.91.124;received=116.15.91.124;branch=z9hG4bK3c62.aad3b76071608423b63106cbdb614472.0
Via: SIP/2.0/UDP 54.71.6.127:5060;branch=z9hG4bK3c62.863eac06ffc83e58df9f8c6659893c5a.0
Via: SIP/2.0/UDP 216.115.69.132;branch=z9hG4bK3c62.e57ec3aa9a48bcf0e659a3828ab9bddd.0
Via: SIP/2.0/UDP 207.223.78.224:5060;branch=z9hG4bK00B9e3a518dd880e5e9
Record-Route: <sip:116.15.91.124;transport=tcp;lr;r2=on>
Record-Route: <sip:116.15.91.124;lr;r2=on>
Record-Route: <sip:216.115.69.132;lr>
Call-ID: 157290149_83336707@207.223.78.224
From: "MONTREAL     QC" <sip:+15144009500@fl.gg>;tag=gK0027fbf1
To: <sip:+12012271232@fl.gg>;tag=UCcbf2NEbY2Ucl41UrOWdQIEUA.s5iBj
CSeq: 189913 INVITE
Contact: <sip:112.15.96.70:3456;transport=TCP>
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Supported: replaces, 100rel, norefersub
Content-Type: application/sdp
Content-Length:   316

v=0
o=- 3792933340 3792933341 IN IP4 112.15.96.70
s=pjmedia
b=AS:84
t=0 0
a=X-nat:0
m=audio 4002 RTP/AVP 0 101
c=IN IP4 112.15.96.70
b=TIAS:64000
a=rtcp:4003 IN IP4 112.15.96.70
a=sendrecv
a=rtpmap:0 PCMU/8000
a=ssrc:1446572610 cname:5893e9c17a7e2bfb
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16

--end msg--
16:36:00.297      tsx0x7f89dc00b038  Retransmit timer event
16:36:00.297      tsx0x7f89dc00b038  .Retransmiting Response msg 200/INVITE/cseq=189913 (tdta0x7f89dc01d018), count=6, restart?=1
16:36:00.297           pjsua_core.c  .TX 1276 bytes Response msg 200/INVITE/cseq=189913 (tdta0x7f89dc01d018) to TCP 116.15.91.124:5060:
SIP/2.0 200 COCO
Via: SIP/2.0/TCP 116.15.91.124;received=116.15.91.124;branch=z9hG4bK3c62.aad3b76071608423b63106cbdb614472.0
Via: SIP/2.0/UDP 54.71.6.127:5060;branch=z9hG4bK3c62.863eac06ffc83e58df9f8c6659893c5a.0
Via: SIP/2.0/UDP 216.115.69.132;branch=z9hG4bK3c62.e57ec3aa9a48bcf0e659a3828ab9bddd.0
Via: SIP/2.0/UDP 207.223.78.224:5060;branch=z9hG4bK00B9e3a518dd880e5e9
Record-Route: <sip:116.15.91.124;transport=tcp;lr;r2=on>
Record-Route: <sip:116.15.91.124;lr;r2=on>
Record-Route: <sip:216.115.69.132;lr>
Call-ID: 157290149_83336707@207.223.78.224
From: "MONTREAL     QC" <sip:+15144009500@fl.gg>;tag=gK0027fbf1
To: <sip:+12012271232@fl.gg>;tag=UCcbf2NEbY2Ucl41UrOWdQIEUA.s5iBj
CSeq: 189913 INVITE
Contact: <sip:112.15.96.70:3456;transport=TCP>
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Supported: replaces, 100rel, norefersub
Content-Type: application/sdp
Content-Length:   316

v=0
o=- 3792933340 3792933341 IN IP4 112.15.96.70
s=pjmedia
b=AS:84
t=0 0
a=X-nat:0
m=audio 4002 RTP/AVP 0 101
c=IN IP4 112.15.96.70
b=TIAS:64000
a=rtcp:4003 IN IP4 112.15.96.70
a=sendrecv
a=rtpmap:0 PCMU/8000
a=ssrc:1446572610 cname:5893e9c17a7e2bfb
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16

--end msg--
16:36:04.298      tsx0x7f89dc00b038  Retransmit timer event
16:36:04.298      tsx0x7f89dc00b038  .Retransmiting Response msg 200/INVITE/cseq=189913 (tdta0x7f89dc01d018), count=7, restart?=1
16:36:04.298           pjsua_core.c  .TX 1276 bytes Response msg 200/INVITE/cseq=189913 (tdta0x7f89dc01d018) to TCP 116.15.91.124:5060:
SIP/2.0 200 COCO
Via: SIP/2.0/TCP 116.15.91.124;received=116.15.91.124;branch=z9hG4bK3c62.aad3b76071608423b63106cbdb614472.0
Via: SIP/2.0/UDP 54.71.6.127:5060;branch=z9hG4bK3c62.863eac06ffc83e58df9f8c6659893c5a.0
Via: SIP/2.0/UDP 216.115.69.132;branch=z9hG4bK3c62.e57ec3aa9a48bcf0e659a3828ab9bddd.0
Via: SIP/2.0/UDP 207.223.78.224:5060;branch=z9hG4bK00B9e3a518dd880e5e9
Record-Route: <sip:116.15.91.124;transport=tcp;lr;r2=on>
Record-Route: <sip:116.15.91.124;lr;r2=on>
Record-Route: <sip:216.115.69.132;lr>
Call-ID: 157290149_83336707@207.223.78.224
From: "MONTREAL     QC" <sip:+15144009500@fl.gg>;tag=gK0027fbf1
To: <sip:+12012271232@fl.gg>;tag=UCcbf2NEbY2Ucl41UrOWdQIEUA.s5iBj
CSeq: 189913 INVITE
Contact: <sip:112.15.96.70:3456;transport=TCP>
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Supported: replaces, 100rel, norefersub
Content-Type: application/sdp
Content-Length:   316

v=0
o=- 3792933340 3792933341 IN IP4 112.15.96.70
s=pjmedia
b=AS:84
t=0 0
a=X-nat:0
m=audio 4002 RTP/AVP 0 101
c=IN IP4 112.15.96.70
b=TIAS:64000
a=rtcp:4003 IN IP4 112.15.96.70
a=sendrecv
a=rtpmap:0 PCMU/8000
a=ssrc:1446572610 cname:5893e9c17a7e2bfb
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16

--end msg--
16:36:08.298      tsx0x7f89dc00b038  Retransmit timer event
16:36:08.298      tsx0x7f89dc00b038  .Retransmiting Response msg 200/INVITE/cseq=189913 (tdta0x7f89dc01d018), count=8, restart?=1
16:36:08.298           pjsua_core.c  .TX 1276 bytes Response msg 200/INVITE/cseq=189913 (tdta0x7f89dc01d018) to TCP 116.15.91.124:5060:
SIP/2.0 200 COCO
Via: SIP/2.0/TCP 116.15.91.124;received=116.15.91.124;branch=z9hG4bK3c62.aad3b76071608423b63106cbdb614472.0
Via: SIP/2.0/UDP 54.71.6.127:5060;branch=z9hG4bK3c62.863eac06ffc83e58df9f8c6659893c5a.0
Via: SIP/2.0/UDP 216.115.69.132;branch=z9hG4bK3c62.e57ec3aa9a48bcf0e659a3828ab9bddd.0
Via: SIP/2.0/UDP 207.223.78.224:5060;branch=z9hG4bK00B9e3a518dd880e5e9
Record-Route: <sip:116.15.91.124;transport=tcp;lr;r2=on>
Record-Route: <sip:116.15.91.124;lr;r2=on>
Record-Route: <sip:216.115.69.132;lr>
Call-ID: 157290149_83336707@207.223.78.224
From: "MONTREAL     QC" <sip:+15144009500@fl.gg>;tag=gK0027fbf1
To: <sip:+12012271232@fl.gg>;tag=UCcbf2NEbY2Ucl41UrOWdQIEUA.s5iBj
CSeq: 189913 INVITE
Contact: <sip:112.15.96.70:3456;transport=TCP>
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Supported: replaces, 100rel, norefersub
Content-Type: application/sdp
Content-Length:   316

v=0
o=- 3792933340 3792933341 IN IP4 112.15.96.70
s=pjmedia
b=AS:84
t=0 0
a=X-nat:0
m=audio 4002 RTP/AVP 0 101
c=IN IP4 112.15.96.70
b=TIAS:64000
a=rtcp:4003 IN IP4 112.15.96.70
a=sendrecv
a=rtpmap:0 PCMU/8000
a=ssrc:1446572610 cname:5893e9c17a7e2bfb
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16

--end msg--
16:36:12.299      tsx0x7f89dc00b038  Retransmit timer event
16:36:12.299      tsx0x7f89dc00b038  .Retransmiting Response msg 200/INVITE/cseq=189913 (tdta0x7f89dc01d018), count=9, restart?=1
16:36:12.299           pjsua_core.c  .TX 1276 bytes Response msg 200/INVITE/cseq=189913 (tdta0x7f89dc01d018) to TCP 116.15.91.124:5060:
SIP/2.0 200 COCO
Via: SIP/2.0/TCP 116.15.91.124;received=116.15.91.124;branch=z9hG4bK3c62.aad3b76071608423b63106cbdb614472.0
Via: SIP/2.0/UDP 54.71.6.127:5060;branch=z9hG4bK3c62.863eac06ffc83e58df9f8c6659893c5a.0
Via: SIP/2.0/UDP 216.115.69.132;branch=z9hG4bK3c62.e57ec3aa9a48bcf0e659a3828ab9bddd.0
Via: SIP/2.0/UDP 207.223.78.224:5060;branch=z9hG4bK00B9e3a518dd880e5e9
Record-Route: <sip:116.15.91.124;transport=tcp;lr;r2=on>
Record-Route: <sip:116.15.91.124;lr;r2=on>
Record-Route: <sip:216.115.69.132;lr>
Call-ID: 157290149_83336707@207.223.78.224
From: "MONTREAL     QC" <sip:+15144009500@fl.gg>;tag=gK0027fbf1
To: <sip:+12012271232@fl.gg>;tag=UCcbf2NEbY2Ucl41UrOWdQIEUA.s5iBj
CSeq: 189913 INVITE
Contact: <sip:112.15.96.70:3456;transport=TCP>
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Supported: replaces, 100rel, norefersub
Content-Type: application/sdp
Content-Length:   316

v=0
o=- 3792933340 3792933341 IN IP4 112.15.96.70
s=pjmedia
b=AS:84
t=0 0
a=X-nat:0
m=audio 4002 RTP/AVP 0 101
c=IN IP4 112.15.96.70
b=TIAS:64000
a=rtcp:4003 IN IP4 112.15.96.70
a=sendrecv
a=rtpmap:0 PCMU/8000
a=ssrc:1446572610 cname:5893e9c17a7e2bfb
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16

--end msg--
16:36:12.797      tsx0x7f89dc00b038  Timeout timer event
16:36:12.797      tsx0x7f89dc00b038  .State changed from Completed to Terminated, event=TIMER
16:36:12.797      dlg0x7f89dc0023a8  ..Transaction tsx0x7f89dc00b038 state changed to Terminated
16:36:12.797               endpoint  ...Request msg BYE/cseq=16432 (tdta0x7f89dc006e38) created.
16:36:12.797      inv0x7f89dc0023a8  ....Sending Request msg BYE/cseq=16432 (tdta0x7f89dc006e38)
16:36:12.797      dlg0x7f89dc0023a8  .....Sending Request msg BYE/cseq=16432 (tdta0x7f89dc006e38)
16:36:12.797      tsx0x7f89dc004ed8  ......Transaction created for Request msg BYE/cseq=16431 (tdta0x7f89dc006e38)
16:36:12.797      tsx0x7f89dc004ed8  .....Sending Request msg BYE/cseq=16431 (tdta0x7f89dc006e38) in state Null
16:36:12.797          sip_resolve.c  ......Target '116.15.91.124:0' type=TCP resolved to '116.15.91.124:5060' type=TCP (TCP transport)
16:36:12.797           pjsua_core.c  ......TX 503 bytes Request msg BYE/cseq=16431 (tdta0x7f89dc006e38) to TCP 116.15.91.124:5060:
BYE sip:+15144009500@207.223.78.224:5060 SIP/2.0
Via: SIP/2.0/TCP 112.15.96.70:41533;rport;branch=z9hG4bKPjwMpM7pUho.duTT3j-OGbnWxC5JOzVdch;alias
Max-Forwards: 70
From: <sip:+12012271232@fl.gg>;tag=UCcbf2NEbY2Ucl41UrOWdQIEUA.s5iBj
To: "MONTREAL     QC" <sip:+15144009500@fl.gg>;tag=gK0027fbf1
Call-ID: 157290149_83336707@207.223.78.224
CSeq: 16431 BYE
Route: <sip:116.15.91.124;transport=tcp;lr;r2=on>
Route: <sip:116.15.91.124;lr;r2=on>
Route: <sip:216.115.69.132;lr>
Content-Length:  0

--end msg--
16:36:12.797      tsx0x7f89dc004ed8  ......State changed from Null to Calling, event=TX_MSG
16:36:12.797      dlg0x7f89dc0023a8  .......Transaction tsx0x7f89dc004ed8 state changed to Calling
16:36:12.798      tsx0x7f89dc00b038  Timeout timer event
16:36:12.798      tsx0x7f89dc00b038  .State changed from Terminated to Destroyed, event=TIMER
16:36:12.798     tdta0x7f89dc01d018  ..Destroying txdata Response msg 200/INVITE/cseq=189913 (tdta0x7f89dc01d018)
16:36:12.798      tsx0x7f89dc00b038  Transaction destroyed!
16:36:12.933         sip_endpoint.c  Processing incoming message: Response msg 200/BYE/cseq=16431 (rdata0x1adf868)
16:36:12.933           pjsua_core.c  .RX 514 bytes Response msg 200/BYE/cseq=16431 (rdata0x1adf868) from TCP 116.15.91.124:5060:
SIP/2.0 200 OK
From: <sip:+12012271232@fl.gg>;tag=UCcbf2NEbY2Ucl41UrOWdQIEUA.s5iBj
To: "MONTREAL     QC" <sip:+15144009500@fl.gg>;tag=gK0027fbf1
Via: SIP/2.0/TCP 112.15.96.70:41533;received=112.15.96.70;rport=41533;branch=z9hG4bKPjwMpM7pUho.duTT3j-OGbnWxC5JOzVdch;alias
Call-ID: 157290149_83336707@207.223.78.224
CSeq: 16431 BYE
Record-Route: <sip:216.115.69.132:5060;lr>
Record-Route: <sip:116.15.91.124:5060;r2=on;lr>
Record-Route: <sip:116.15.91.124:5060;transport=tcp;r2=on;lr>
Content-Length: 0

--end msg--
16:36:12.933      tsx0x7f89dc004ed8  .Incoming Response msg 200/BYE/cseq=16431 (rdata0x1adf868) in state Calling
16:36:12.933      tsx0x7f89dc004ed8  ..State changed from Calling to Completed, event=RX_MSG
16:36:12.933      dlg0x7f89dc0023a8  ...Received Response msg 200/BYE/cseq=16431 (rdata0x1adf868)
16:36:12.933      dlg0x7f89dc0023a8  ...Transaction tsx0x7f89dc004ed8 state changed to Completed
16:36:12.933          pjsua_media.c  .....Call 1: deinitializing media..
16:36:12.934     strm0x7f89dc021a98  .......JB summary:
  size=50/eff=50 prefetch=0 level=0
  delay (min/max/avg/dev)=0/0/0/0 ms
  burst (min/max/avg/dev)=0/0/0/0 frames
  lost=0 discard=996 empty=0
16:36:12.934          pjsua_media.c  .......Media stream call01:0 is destroyed
16:36:12.934      dlg0x7f89dc0023a8  .....Session count dec to 1 by mod-invite
16:36:12.934      tsx0x7f89dc004ed8  Timeout timer event
16:36:12.934      tsx0x7f89dc004ed8  .State changed from Completed to Terminated, event=TIMER
16:36:12.934      dlg0x7f89dc0023a8  ..Transaction tsx0x7f89dc004ed8 state changed to Terminated
16:36:12.934      dlg0x7f89dc0023a8  ...Dialog destroyed!
16:36:12.934      tsx0x7f89dc004ed8  Timeout timer event
16:36:12.934      tsx0x7f89dc004ed8  .State changed from Terminated to Destroyed, event=TIMER
16:36:12.934     tdta0x7f89dc006e38  ..Destroying txdata Request msg BYE/cseq=16431 (tdta0x7f89dc006e38)
16:36:12.934      tsx0x7f89dc004ed8  Transaction destroyed!
16:36:13.047           pjsua_core.c !Shutting down, flags=0...
16:36:13.047           pjsua_core.c  PJSUA state changed: RUNNING --> CLOSING
16:36:13.055           pjsua_call.c  .Hangup all calls..
nanangizz commented 4 years ago

AFAIK, that's the nature of TCP, i.e: the message receiver should be able to detect SIP message boundaries. Please confirm and provide more info (e.g: PJSIP version, reproducing steps using pjsua app, etc) if the receiver happens to be PJSIP based.

jchavanton commented 4 years ago

Hi,

Notice the corruption with the ACK in the middle of the body.

INVITE sip:+12012271232@sip.sipdomain.com;transport=tcp SIP/2.0
Via: SIP/2.0/TCP 112.15.96.70:3456;rport;branch=z9hG4bKPj4tHlNqYReRoNkf6L59pEs.7ccJWxwimu;alias
Max-Forwards: 70
From: sip:+15144009500@customer-mock.xyz;tag=LvIv94oFW.UDfCtNtTKkO93W.P9LSfOX
To: sip:+12012271232@sip.sipdomain.com
Contact: <sip:+15144009500@112.15.96.70:41533;transport=TCP;ob>
Call-ID: aXi-10AOXRgvOigH98HPvYWCO2gO1ktC
CSeq: 10022 INVITE
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Supported: replaces, 100rel, timer, norefersub
Session-Expires: 1800
Min-SE: 90
Proxy-Authorization: Digest username="367613170", realm="sip.sipdomain.com", nonce="XmkUh15pE1vBV+MCRz4jgE5MCfERV7Kc", uri="sip:+12012271232@sip.sipdomain.com;transport=tcp", response="9ef2d66729d924bafa21
2057e9cb7a", cnonce="dqQzKJHQPBRdHu4NEHDYDC4xIdVvkP1M", qop=auth, nc=00000001
Content-Type: application/sdp
Content-Length:   340

v=0
o=- 3792933339 3792933339 IN IP4 112.15.96.70
s=pjmedia
b=AS:84
t=0 0
ACK sip:+12012271232@sip.sipdomain.com;transport=tcp SIP/2.0
Via: SIP/2.0/TCP 112.15.96.70:3456;rport;branch=z9hG4bKPjAdtpUlfpai5xv4n2inr0KkroIDLpS9TG;alias
Max-Forwards: 70
From: sip:+15144009500@customer-mock.xyz;tag=LvIv94oFW.UDfCtNtTKkO93W.P9LSfOX
To: sip:+12012271232@sip.sipdomain.com;tag=bf8638324618dc61059d4c604476fea1.bb6d
Call-ID: aXi-10AOXRgvOigH98HPvYWCO2gO1ktC
CSeq: 10021 ACK
Content-Length:  0

I tested tested latest master pjproject as well some older versions, I will test further back to isolate potential sources of the problem. I can not reproduce on every computer, not sure if it could be related to a timing issue.

I am testing register, and calling itself, I will test only calling out to keep reproducibility as simple as possible.

I understand, it may be challenging for you reproduce as it may also be caused by the integration in Voip_Patrol, however the challenge re-invite is handle automatically but pjsua.

I will find some time to dig it further, maybe debugging it.

I wanted to have a second opinion in case there could be an obvious explanation that I could be missing.

Thank you

jchavanton commented 4 years ago

I wonder if it could be related to the way I am using the transports, creating them UDP/TCP/TLS and selecting the one explicitly in the account before making a call, maybe I should let pjsua do it automatically ...

However pjsua logs are not reporting anything wrong as far as I can tell ...

Example: When making a call I leave the trasport selection to pjsua

call->makeCall("sip:"+callee+";transport=tcp", prm, to_uri);

When registering to a different transport, I am forcing the transport using account modify

if (transport == "tcp") {
        acc_cfg.sipConfig.transportId = config->transport_id_tcp;
...
acc->modify(acc_cfg);

Also I assuming that transports can be shared between accounts. I think I double checked in the default app.

jchavanton commented 4 years ago

I did test very old versions and I can still reproduce on some new hosts, could some library update, I will dig it further.

jchavanton commented 4 years ago

register on one account overlapping a makeCall on another account using the same transport.

[06:02:58.382][INFO] createAccount: [1][sip:user1@sip.test-domain.com]
[06:02:58.381][INFO] do_register >> sip:user1@sip.test-domain.com
[06:02:58.382][INFO] createAccount: [2][sip:user2@customer-mock.xyz;transport=tcp]
[06:02:58.382][INFO] makeCall Fast-Start: flag:4 PJSUA_CALL_NO_SDP_OFFER:8
[06:02:58.402][INFO] onCallState: [sip:user2@customer-mock.xyz;transport=tcp]
[06:02:58.402][INFO] onCallState: [0]role[CALLER]id[TU6Eo8NayvRwsaLQMoSZO8eUKshzEr4V][sip:user2@customer-mock.xyz;transport=tcp][sip:+14203011035@sip.test-domain.com;transport=tcp][CALLING|1]
[06:02:58.402][INFO] onCallTsxState: [0][sip:+14503001085@sip.test-domain.com;transport=tcp][CALLING]id[TU6Eo8NayvRwsaLQMoSZO8eUKshzEr4V] call[0] reason[]
[06:02:58.402][INFO] do_wait duration_ms:0 complete all tests:1
[06:02:58.566][INFO] onCallTsxState: [0][sip:+14503001085@sip.test-domain.com;transport=tcp][CALLING]id[TU6Eo8NayvRwsaLQMoSZO8eUKshzEr4V]
[06:02:58.679][INFO] [Register] code:200
jchavanton commented 4 years ago

Should I revisit the sharing transport between accounts ... I wonder why this is not safe

jchavanton commented 4 years ago

Could be worth nothing that the same ephemeral port is used for both the register and the makeCall even if they are on different accounts.

sauwming commented 4 years ago

Have you managed to test with the latest version?

Sharing the transport should be fine and in fact it is the library's default behavior to reuse a transport whenever possible.

Another useful investigative tool here is to use packet capture to check if the packet itself already arrives in a mangled state.

jchavanton commented 4 years ago

Is it possible to use one socket / account ? Or do I have to create a new transport ?

parthbarot10 commented 3 years ago

@jchavanton I am facing automatic call drops issue due to NAT Issue. It sends private IP in contact header and due to that TCP Sessions are closing and changes the port and my ongoing VoIP call is dropped via BYE request automatically. Do you have any solution for this? Or Does my issue is the same as the issue you posted here?

I searched my issue and I think it is happening due to loss of ACK while use private IP. Reference Link:- https://blog.opensips.org/2017/02/22/troubleshooting-missing-ack-in-sip/

Please tell me a solution for this if you can help me.

jchavanton commented 3 years ago

Hi, to be related to this issue the packet/message content must be corrupted, like if a char buffer overflow/overwritten. Did you find any such evidence in a trace ?

parthbarot10 commented 3 years ago

@jchavanton I have implemented the SDK for this and using in two different apps but only facing this issue on one app only. The process for both is same though facing issue on only one app. Below I have attached the tarce log for both working app and non working app. Can you please look into this and share your thoughts on this if found any issue regarding buffer overflow/overwitten.

Call App Issue Log.zip Number App Working Log.zip

jchavanton commented 3 years ago

If it is the same issue, you will see is in a network capture, not in the pjsip logs. "facing automatic call drops issue due to NAT Issue" does not seems likely to be the same issue.

sauwming commented 1 year ago

Since the issue has been quite a while, let us know if it still persists in the latest version.