I'm fairly new to PJSIP, and am using PJSIP 2.5.5 to build a SIP Client into an existing application. Every thing works fine when I am using an Asterisk server, but when connecting to an Avaya the outgoing call takes up to 10 seconds to connect to the another client. Calling from media5-fone to my app does not have this Issue, so I suspect a configuration issue on my side. I am using TCP transport, UDP has been disabled on the Server.
Is anyone able to help out?
In this case it took about 6 seconds for the other app to receive the Invite.
Thanks
Here is the Sip Trace
2016-10-12 18:06:07.568 JCTComms[755:200829] Reconnecting
18:06:07.572 os_core_unix.c !pjlib 2.5.5 for POSIX initialized
18:06:07.583 sip_endpoint.c .Creating endpoint instance...
18:06:07.584 pjlib .select() I/O Queue created (0x14bae144)
18:06:07.585 sip_endpoint.c .Module "mod-msg-print" registered
18:06:07.585 sip_transport. .Transport manager created.
18:06:07.585 pjsua_core.c .PJSUA state changed: NULL --> CREATED
18:06:07.587 sip_endpoint.c .Module "mod-pjsua-log" registered
18:06:07.587 sip_endpoint.c .Module "mod-tsx-layer" registered
18:06:07.587 sip_endpoint.c .Module "mod-stateful-util" registered
18:06:07.587 sip_endpoint.c .Module "mod-ua" registered
18:06:07.588 sip_endpoint.c .Module "mod-100rel" registered
18:06:07.588 sip_endpoint.c .Module "mod-pjsua" registered
18:06:07.590 sip_endpoint.c .Module "mod-invite" registered
18:06:07.644 coreaudio_dev. .. dev_id 0: iPhone IO device (in=1, out=1) 8000Hz
18:06:07.649 coreaudio_dev. ..core audio initialized
18:06:07.651 pjlib ..select() I/O Queue created (0x14bb9814)
18:06:07.651 speex_codec.c ..Adjusting quality to 5 for uwb
18:06:07.661 conference.c ..Creating conference bridge with 73 ports
18:06:07.663 Master/sound ..Using delay buffer with WSOLA.
18:06:07.669 sip_endpoint.c .Module "mod-evsub" registered
18:06:07.670 sip_endpoint.c .Module "mod-presence" registered
18:06:07.670 evsub.c .Event pkg "presence" registered by mod-presence
18:06:07.670 sip_endpoint.c .Module "mod-mwi" registered
18:06:07.670 evsub.c .Event pkg "message-summary" registered by mod-mwi
18:06:07.671 sip_endpoint.c .Module "mod-refer" registered
18:06:07.671 evsub.c .Event pkg "refer" registered by mod-refer
18:06:07.672 sip_endpoint.c .Module "mod-pjsua-pres" registered
18:06:07.672 sip_endpoint.c .Module "mod-pjsua-im" registered
18:06:07.673 sip_endpoint.c .Module "mod-pjsua-options" registered
18:06:07.673 pjsua_core.c .1 SIP worker threads created
18:06:07.673 pjsua_core.c .pjsua version 2.5.5 for iPhone OS-9.3.2/arm-iPad3,6/iOS-SDK-10.0 initialized
18:06:07.674 pjsua_core.c .PJSUA state changed: CREATED --> INIT
18:06:07.675 sip_endpoint.c Module "mod-default-handler" registered
18:06:07.678 pjsua_core.c SIP UDP socket reachable at 172.30.0.202:5060
18:06:07.679 udp0x14bab000 SIP UDP transport started, published address is 172.30.0.202:5060
18:06:07.680 pjsua_acc.c Adding account: id=<sip:172.30.0.202:5060>
18:06:07.680 pjsua_acc.c .Account <sip:172.30.0.202:5060> added with id 0
18:06:07.681 pjsua_acc.c Modifying account 0
18:06:07.682 pjsua_acc.c Acc 0: setting online status to 1..
18:06:07.685 tcptp:5060 SIP TCP listener ready for incoming connections at 172.30.0.202:5060
18:06:07.685 pjsua_acc.c Adding account: id=<sip:172.30.0.202:5060;transport=TCP>
18:06:07.686 pjsua_acc.c .Account <sip:172.30.0.202:5060;transport=TCP> added with id 1
18:06:07.686 pjsua_acc.c Modifying account 1
18:06:07.687 pjsua_acc.c Acc 1: setting online status to 1..
18:06:07.687 pjsua_core.c PJSUA state changed: INIT --> STARTING
18:06:07.688 sip_endpoint.c .Module "mod-unsolicited-mwi" registered
18:06:07.690 pjsua_core.c .PJSUA state changed: STARTING --> RUNNING
18:06:08.498 pjsua_acc.c !Deleting account 1..
18:06:08.498 pjsua_acc.c .Account id 1 deleted
18:06:08.498 pjsua_acc.c Adding account: id=sip:4742@172.30.38.20
18:06:08.498 pjsua_acc.c .Account sip:4742@172.30.38.20 added with id 1
18:06:08.498 pjsua_acc.c .Acc 1: setting registration..
18:06:08.505 tcpc0x14c36614 ..TCP client transport created
18:06:08.505 tcpc0x14c36614 ..TCP transport 172.30.0.202:55093 is connecting to 172.30.38.20:5060...
18:06:08.505 pjsua_acc.c ..Contact for acc 1 updated for SIP outbound: <sip:4742@172.30.0.202:55093;transport=TCP;ob>;reg-id=1;+sip.instance="<urn:uuid:00000000-0000-0000-0000-000035569cf7>"
18:06:08.505 endpoint ..Request msg REGISTER/cseq=63903 (tdta0x14c34600) created.
18:06:08.507 tsx0x14c31a64 ...Transaction created for Request msg REGISTER/cseq=63904 (tdta0x14c34600)
18:06:08.507 tsx0x14c31a64 ..Sending Request msg REGISTER/cseq=63904 (tdta0x14c34600) in state Null
18:06:08.507 sip_resolve.c ...Target '172.30.38.20:5060' type=TCP resolved to '172.30.38.20:5060' type=TCP (TCP transport)
18:06:08.515 pjsua_core.c ...TX 699 bytes Request msg REGISTER/cseq=63904 (tdta0x14c34600) to TCP 172.30.38.20:5060:
REGISTER sip:172.30.38.20:5060;transport=tcp SIP/2.0
Via: SIP/2.0/TCP 172.30.0.202:55093;rport;branch=z9hG4bKPj6MS-nUSrO1GmBXb-L59VSVHJw3Orv548;alias
Route: <sip:172.30.38.20:5060;transport=tcp;lr>
Max-Forwards: 70
From: <sip:4742@172.30.38.20>;tag=5ODLRfzWTt.cH9VgEEpJsTGgq2pJiVic
To: <sip:4742@172.30.38.20>
Call-ID: WK50hvGirkAhjIkmXO0vCktKqnFBdoO2
CSeq: 63904 REGISTER
User-Agent: JCT Messenger
Supported: outbound, path
Contact: <sip:4742@172.30.0.202:55093;transport=TCP;ob>;reg-id=1;+sip.instance="<urn:uuid:00000000-0000-0000-0000-000035569cf7>"
Expires: 720
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Content-Length: 0
--end msg--
18:06:08.515 tsx0x14c31a64 ...State changed from Null to Calling, event=TX_MSG
18:06:08.515 pjsua_acc.c ..Acc 1: Registration sent
18:06:08.620 tcpc0x14c36614 !TCP transport 172.30.0.202:55093 is connected to 172.30.38.20:5060
18:06:08.620 pjsua_app.c SIP TCP transport is connected to [172.30.38.20:5060]
18:06:08.721 sip_endpoint.c Processing incoming message: Response msg 401/REGISTER/cseq=63904 (rdata0x14c367d4)
18:06:08.721 pjsua_core.c .RX 593 bytes Response msg 401/REGISTER/cseq=63904 (rdata0x14c367d4) from TCP 172.30.38.20:5060:
SIP/2.0 401 Unauthorized
Via: SIP/2.0/TCP 172.30.0.202:55093;rport;branch=z9hG4bKPj6MS-nUSrO1GmBXb-L59VSVHJw3Orv548;alias
From: <sip:4742@172.30.38.20>;tag=5ODLRfzWTt.cH9VgEEpJsTGgq2pJiVic
Call-ID: WK50hvGirkAhjIkmXO0vCktKqnFBdoO2
CSeq: 63904 REGISTER
User-Agent: IP Office 9.0.6.0 build 979
Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,REFER,NOTIFY,INFO,SUBSCRIBE,REGISTER,PUBLISH
WWW-Authenticate: Digest nonce="0a00921e107b3c39d659",realm="ipoffice",algorithm=MD5
Supported: timer
Server: IP Office 9.0.6.0 build 979
To: <sip:4742@172.30.38.20>;tag=9f1e75e41356afe2
Content-Length: 0
--end msg--
18:06:08.721 tsx0x14c31a64 .Incoming Response msg 401/REGISTER/cseq=63904 (rdata0x14c367d4) in state Calling
18:06:08.721 tsx0x14c31a64 ..State changed from Calling to Completed, event=RX_MSG
18:06:08.727 tsx0x153de264 ....Transaction created for Request msg REGISTER/cseq=63905 (tdta0x14c34600)
18:06:08.727 tsx0x153de264 ...Sending Request msg REGISTER/cseq=63905 (tdta0x14c34600) in state Null
18:06:08.727 endpoint ....Request msg REGISTER/cseq=63905 (tdta0x14c34600): skipping target resolution because address is already set
18:06:08.727 pjsua_core.c ....TX 889 bytes Request msg REGISTER/cseq=63905 (tdta0x14c34600) to TCP 172.30.38.20:5060:
REGISTER sip:172.30.38.20:5060;transport=tcp SIP/2.0
Via: SIP/2.0/TCP 172.30.0.202:55093;rport;branch=z9hG4bKPj-YmZsrRRcqdiFpf.sh4sZVJP3WmXXnJE;alias
Route: <sip:172.30.38.20:5060;transport=tcp;lr>
Max-Forwards: 70
From: <sip:4742@172.30.38.20>;tag=5ODLRfzWTt.cH9VgEEpJsTGgq2pJiVic
To: <sip:4742@172.30.38.20>
Call-ID: WK50hvGirkAhjIkmXO0vCktKqnFBdoO2
CSeq: 63905 REGISTER
User-Agent: JCT Messenger
Supported: outbound, path
Contact: <sip:4742@172.30.0.202:55093;transport=TCP;ob>;reg-id=1;+sip.instance="<urn:uuid:00000000-0000-0000-0000-000035569cf7>"
Expires: 720
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Authorization: Digest username="4742", realm="ipoffice", nonce="0a00921e107b3c39d659", uri="sip:172.30.38.20:5060;transport=tcp", response="b5ae24de8dd6e0525f44387b3cb772f6", algorithm=MD5
Content-Length: 0
--end msg--
18:06:08.736 tsx0x153de264 ....State changed from Null to Calling, event=TX_MSG
18:06:08.744 tsx0x14c31a64 Timeout timer event
18:06:08.744 tsx0x14c31a64 .State changed from Completed to Terminated, event=TIMER
18:06:08.744 tsx0x14c31a64 Timeout timer event
18:06:08.744 tsx0x14c31a64 .State changed from Terminated to Destroyed, event=TIMER
18:06:08.744 tsx0x14c31a64 Transaction destroyed!
18:06:08.841 sip_endpoint.c Processing incoming message: Response msg 200/REGISTER/cseq=63905 (rdata0x14c367d4)
18:06:08.841 pjsua_core.c .RX 605 bytes Response msg 200/REGISTER/cseq=63905 (rdata0x14c367d4) from TCP 172.30.38.20:5060:
SIP/2.0 200 OK
Via: SIP/2.0/TCP 172.30.0.202:55093;rport;branch=z9hG4bKPj-YmZsrRRcqdiFpf.sh4sZVJP3WmXXnJE;alias
From: <sip:4742@172.30.38.20>;tag=5ODLRfzWTt.cH9VgEEpJsTGgq2pJiVic
Call-ID: WK50hvGirkAhjIkmXO0vCktKqnFBdoO2
CSeq: 63905 REGISTER
User-Agent: IP Office 9.0.6.0 build 979
Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,REFER,NOTIFY,INFO,SUBSCRIBE,REGISTER,PUBLISH
Contact: <sip:4742@172.30.0.202:55093;transport=TCP;ob>
Date: Wed, 12 Oct 2016 07:35:58 GMT
Expires: 180
Supported: timer
Server: IP Office 9.0.6.0 build 979
To: <sip:4742@172.30.38.20>;tag=8bf9216eda9c9390
Content-Length: 0
--end msg--
18:06:08.841 tsx0x153de264 .Incoming Response msg 200/REGISTER/cseq=63905 (rdata0x14c367d4) in state Calling
18:06:08.841 tsx0x153de264 ..State changed from Calling to Completed, event=RX_MSG
18:06:08.844 pjsua_acc.c ....SIP outbound status for acc 1 is not active
18:06:08.844 pjsua_acc.c ....sip:4742@172.30.38.20: registration success, status=200 (OK), will re-register in 180 seconds
18:06:08.844 tsx0x153de264 Timeout timer event
18:06:08.844 tsx0x153de264 .State changed from Completed to Terminated, event=TIMER
18:06:08.844 tsx0x153de264 Timeout timer event
18:06:08.844 tsx0x153de264 .State changed from Terminated to Destroyed, event=TIMER
18:06:08.844 tdta0x14c34600 ..Destroying txdata Request msg REGISTER/cseq=63905 (tdta0x14c34600)
18:06:08.844 tsx0x153de264 Transaction destroyed!
18:06:35.866 pjsua_call.c !Making call with acc #1 to sip:4743@172.30.38.20
18:06:35.866 pjsua_aud.c .Set sound device: capture=-1, playback=-2
18:06:35.866 pjsua_app.c ..Turning sound device ON
18:06:35.866 pjsua_aud.c ..Opening sound device (speaker + mic) PCM@16000/1/20ms
18:06:35.866 coreaudio_dev. ...Using VoiceProcessingIO audio unit
18:06:36.096 coreaudio_dev. ...core audio stream started
18:06:36.101 dlg0x153fe664 .UAC dialog created
18:06:36.101 dlg0x153fe664 ..Session count inc to 2 by mod-pjsua
18:06:36.101 pjsua_media.c .Call 0: initializing media..
18:06:36.101 pjsua_media.c ..RTP socket reachable at 172.30.0.202:4000
18:06:36.101 pjsua_media.c ..RTCP socket reachable at 172.30.0.202:4001
18:06:36.102 pjsua_media.c ..Media index 0 selected for audio call 0
18:06:36.102 dlg0x153fe664 ..Session count dec to 2 by mod-pjsua
18:06:36.102 dlg0x153fe664 .Module mod-invite added as dialog usage, data=0x1538d6e4
18:06:36.102 dlg0x153fe664 ..Session count inc to 4 by mod-invite
18:06:36.102 dlg0x153fe664 .Module mod-100rel added as dialog usage, data=0x1539c988
18:06:36.102 dlg0x153fe664 .100rel module attached
18:06:36.102 inv0x153fe664 .UAC invite session created for dialog dlg0x153fe664
18:06:36.102 endpoint .Request msg INVITE/cseq=29601 (tdta0x15403800) created.
18:06:36.102 inv0x153fe664 ..Sending Request msg INVITE/cseq=29601 (tdta0x15403800)
18:06:36.102 dlg0x153fe664 ...Sending Request msg INVITE/cseq=29601 (tdta0x15403800)
18:06:36.106 tsx0x15405864 ....Transaction created for Request msg INVITE/cseq=29600 (tdta0x15403800)
18:06:36.106 tsx0x15405864 ...Sending Request msg INVITE/cseq=29600 (tdta0x15403800) in state Null
18:06:36.106 sip_resolve.c ....Target '172.30.38.20:5060' type=TCP resolved to '172.30.38.20:5060' type=TCP (TCP transport)
18:06:36.106 pjsua_core.c ....TX 1153 bytes Request msg INVITE/cseq=29600 (tdta0x15403800) to TCP 172.30.38.20:5060:
INVITE sip:4743@172.30.38.20 SIP/2.0
Via: SIP/2.0/TCP 172.30.0.202:55093;rport;branch=z9hG4bKPjwHAvb0PCcoewU7nF.39cL2N5AiMAGrvG;alias
Max-Forwards: 70
From: sip:4742@172.30.38.20;tag=0kqd-cxo2dM8SFv05fxlJH8UGHzXdUZe
To: sip:4743@172.30.38.20
Contact: <sip:4742@172.30.0.202:55093;transport=TCP;ob>
Call-ID: NC.T6KcR7Rv-Sno23807LLcoBn1ZosfT
CSeq: 29600 INVITE
Route: <sip:172.30.38.20:5060;transport=tcp;lr>
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Supported: replaces, 100rel, timer, norefersub
Session-Expires: 1800
Min-SE: 90
User-Agent: JCT Messenger
Content-Type: application/sdp
Content-Length: 473
v=0
o=- 3685246596 3685246596 IN IP4 172.30.0.202
s=pjmedia
b=AS:84
t=0 0
a=X-nat:0
m=audio 4000 RTP/AVP 98 97 99 104 3 0 8 9 96
c=IN IP4 172.30.0.202
b=TIAS:64000
a=rtcp:4001 IN IP4 172.30.0.202
a=sendrecv
a=rtpmap:98 speex/16000
a=rtpmap:97 speex/8000
a=rtpmap:99 speex/32000
a=rtpmap:104 iLBC/8000
a=fmtp:104 mode=30
a=rtpmap:3 GSM/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:9 G722/8000
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-16
--end msg--
18:06:36.111 tsx0x15405864 ....State changed from Null to Calling, event=TX_MSG
18:06:36.111 dlg0x153fe664 .....Transaction tsx0x15405864 state changed to Calling
18:06:36.112 pjsua_app.c .......Call 0 state changed to CALLING
18:06:36.116 coreaudio_dev. !Recorder thread started, (372 frames)
18:06:36.116 os_core_unix.c Info: possibly re-registering existing thread
18:06:36.116 coreaudio_dev. !Player thread started, (372 frames)
18:06:42.828 sip_endpoint.c !Processing incoming message: Response msg 100/INVITE/cseq=29600 (rdata0x14c367d4)
18:06:42.830 pjsua_core.c .RX 472 bytes Response msg 100/INVITE/cseq=29600 (rdata0x14c367d4) from TCP 172.30.38.20:5060:
SIP/2.0 100 Trying
Via: SIP/2.0/TCP 172.30.0.202:55093;rport;branch=z9hG4bKPjwHAvb0PCcoewU7nF.39cL2N5AiMAGrvG;alias
From: <sip:4742@172.30.38.20>;tag=0kqd-cxo2dM8SFv05fxlJH8UGHzXdUZe
Call-ID: NC.T6KcR7Rv-Sno23807LLcoBn1ZosfT
CSeq: 29600 INVITE
Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,INFO,REFER,NOTIFY,SUBSCRIBE,REGISTER,PUBLISH,UPDATE
Supported: timer,100rel
Server: IP Office 9.0.6.0 build 979
To: <sip:4743@172.30.38.20>;tag=a747f750afce40c6
Content-Length: 0
--end msg--
18:06:42.830 tsx0x15405864 .Incoming Response msg 100/INVITE/cseq=29600 (rdata0x14c367d4) in state Calling
18:06:42.830 tsx0x15405864 ..State changed from Calling to Proceeding, event=RX_MSG
18:06:42.830 dlg0x153fe664 ...Received Response msg 100/INVITE/cseq=29600 (rdata0x14c367d4)
18:06:42.830 dlg0x153fe664 ...Transaction tsx0x15405864 state changed to Proceeding
18:06:44.921 sip_endpoint.c Processing incoming message: Response msg 180/INVITE/cseq=29600 (rdata0x14c367d4)
18:06:44.922 pjsua_core.c .RX 607 bytes Response msg 180/INVITE/cseq=29600 (rdata0x14c367d4) from TCP 172.30.38.20:5060:
SIP/2.0 180 Ringing
Via: SIP/2.0/TCP 172.30.0.202:55093;rport;branch=z9hG4bKPjwHAvb0PCcoewU7nF.39cL2N5AiMAGrvG;alias
From: <sip:4742@172.30.38.20>;tag=0kqd-cxo2dM8SFv05fxlJH8UGHzXdUZe
Call-ID: NC.T6KcR7Rv-Sno23807LLcoBn1ZosfT
CSeq: 29600 INVITE
Contact: "LNursecall03" <sip:4743@172.30.38.20:5060;transport=tcp>
Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,INFO,REFER,NOTIFY,SUBSCRIBE,REGISTER,PUBLISH,UPDATE
P-Asserted-Identity: "LNursecall03" <sip:4743@172.30.38.20:5060>
Supported: timer,100rel
Server: IP Office 9.0.6.0 build 979
To: <sip:4743@172.30.38.20>;tag=a747f750afce40c6
Content-Length: 0
--end msg--
18:06:44.922 tsx0x15405864 .Incoming Response msg 180/INVITE/cseq=29600 (rdata0x14c367d4) in state Proceeding
18:06:44.922 tsx0x15405864 ..State changed from Proceeding to Proceeding, event=RX_MSG
18:06:44.922 dlg0x153fe664 ...Received Response msg 180/INVITE/cseq=29600 (rdata0x14c367d4)
18:06:44.922 dlg0x153fe664 ....Route-set updated
18:06:44.922 dlg0x153fe664 ...Transaction tsx0x15405864 state changed to Proceeding
18:06:44.923 pjsua_aud.c .....Conf connect: 1 --> 0
18:06:44.923 conference.c ......Port 1 (ringback) transmitting to port 0 (iPhone IO device)
18:06:44.924 pjsua_app.c .....Call 0 state changed to EARLY (180 Ringing)
18:06:46.467 pjsua_call.c !Call 0 hanging up: code=0..
18:06:46.467 endpoint ..Request msg CANCEL/cseq=29600 (tdta0x14c51400) created.
18:06:46.467 inv0x153fe664 ..Sending Request msg CANCEL/cseq=29600 (tdta0x14c51400)
18:06:46.467 dlg0x153fe664 ...Sending Request msg CANCEL/cseq=29600 (tdta0x14c51400)
18:06:46.467 tsx0x14c4ea64 ....Transaction created for Request msg CANCEL/cseq=29600 (tdta0x14c51400)
18:06:46.467 tsx0x14c4ea64 ...Sending Request msg CANCEL/cseq=29600 (tdta0x14c51400) in state Null
18:06:46.467 endpoint ....Request msg CANCEL/cseq=29600 (tdta0x14c51400): skipping target resolution because address is already set
18:06:46.467 pjsua_core.c ....TX 408 bytes Request msg CANCEL/cseq=29600 (tdta0x14c51400) to TCP 172.30.38.20:5060:
CANCEL sip:4743@172.30.38.20 SIP/2.0
Via: SIP/2.0/TCP 172.30.0.202:55093;rport;branch=z9hG4bKPjwHAvb0PCcoewU7nF.39cL2N5AiMAGrvG;alias
Max-Forwards: 70
From: sip:4742@172.30.38.20;tag=0kqd-cxo2dM8SFv05fxlJH8UGHzXdUZe
To: sip:4743@172.30.38.20
Call-ID: NC.T6KcR7Rv-Sno23807LLcoBn1ZosfT
CSeq: 29600 CANCEL
Route: <sip:172.30.38.20:5060;transport=tcp;lr>
User-Agent: JCT Messenger
Content-Length: 0
--end msg--
18:06:46.469 tsx0x14c4ea64 ....State changed from Null to Calling, event=TX_MSG
18:06:46.469 dlg0x153fe664 .....Transaction tsx0x14c4ea64 state changed to Calling
18:06:46.572 sip_endpoint.c !Processing incoming message: Response msg 200/CANCEL/cseq=29600 (rdata0x14c367d4)
18:06:46.572 pjsua_core.c .RX 378 bytes Response msg 200/CANCEL/cseq=29600 (rdata0x14c367d4) from TCP 172.30.38.20:5060:
SIP/2.0 200 OK
Via: SIP/2.0/TCP 172.30.0.202:55093;rport;branch=z9hG4bKPjwHAvb0PCcoewU7nF.39cL2N5AiMAGrvG;alias
From: <sip:4742@172.30.38.20>;tag=0kqd-cxo2dM8SFv05fxlJH8UGHzXdUZe
Call-ID: NC.T6KcR7Rv-Sno23807LLcoBn1ZosfT
CSeq: 29600 CANCEL
Supported: timer,100rel
Server: IP Office 9.0.6.0 build 979
To: <sip:4743@172.30.38.20>;tag=a747f750afce40c6
Content-Length: 0
--end msg--
18:06:46.573 tsx0x14c4ea64 .Incoming Response msg 200/CANCEL/cseq=29600 (rdata0x14c367d4) in state Calling
18:06:46.573 tsx0x14c4ea64 ..State changed from Calling to Completed, event=RX_MSG
18:06:46.573 dlg0x153fe664 ...Received Response msg 200/CANCEL/cseq=29600 (rdata0x14c367d4)
18:06:46.573 dlg0x153fe664 ...Transaction tsx0x14c4ea64 state changed to Completed
18:06:46.573 sip_endpoint.c Processing incoming message: Response msg 487/INVITE/cseq=29600 (rdata0x14c367d4)
18:06:46.573 pjsua_core.c .RX 484 bytes Response msg 487/INVITE/cseq=29600 (rdata0x14c367d4) from TCP 172.30.38.20:5060:
SIP/2.0 487 Request Terminated
Via: SIP/2.0/TCP 172.30.0.202:55093;rport;branch=z9hG4bKPjwHAvb0PCcoewU7nF.39cL2N5AiMAGrvG;alias
From: <sip:4742@172.30.38.20>;tag=0kqd-cxo2dM8SFv05fxlJH8UGHzXdUZe
Call-ID: NC.T6KcR7Rv-Sno23807LLcoBn1ZosfT
CSeq: 29600 INVITE
Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,INFO,REFER,NOTIFY,SUBSCRIBE,REGISTER,PUBLISH,UPDATE
Supported: timer,100rel
Server: IP Office 9.0.6.0 build 979
To: <sip:4743@172.30.38.20>;tag=a747f750afce40c6
Content-Length: 0
--end msg--
18:06:46.574 tsx0x15405864 .Incoming Response msg 487/INVITE/cseq=29600 (rdata0x14c367d4) in state Proceeding
18:06:46.574 endpoint ..Request msg ACK/cseq=29600 (tdta0x14c54400) created.
18:06:46.574 pjsua_core.c ..TX 396 bytes Request msg ACK/cseq=29600 (tdta0x14c54400) to TCP 172.30.38.20:5060:
ACK sip:4743@172.30.38.20 SIP/2.0
Via: SIP/2.0/TCP 172.30.0.202:55093;rport;branch=z9hG4bKPjwHAvb0PCcoewU7nF.39cL2N5AiMAGrvG;alias
Max-Forwards: 70
From: sip:4742@172.30.38.20;tag=0kqd-cxo2dM8SFv05fxlJH8UGHzXdUZe
To: sip:4743@172.30.38.20;tag=a747f750afce40c6
Call-ID: NC.T6KcR7Rv-Sno23807LLcoBn1ZosfT
CSeq: 29600 ACK
Route: <sip:172.30.38.20:5060;transport=tcp;lr>
Content-Length: 0
--end msg--
18:06:46.574 tsx0x15405864 ..State changed from Proceeding to Completed, event=RX_MSG
18:06:46.575 dlg0x153fe664 ...Received Response msg 487/INVITE/cseq=29600 (rdata0x14c367d4)
18:06:46.575 dlg0x153fe664 ...Transaction tsx0x15405864 state changed to Completed
18:06:46.580 pjsua_aud.c .....Conf disconnect: 1 -x- 0
18:06:46.580 conference.c ......Port 1 (ringback) stop transmitting to port 0 (iPhone IO device)
18:06:46.580 pjsua_app.c .....Call 0 is DISCONNECTED [reason=487 (Request Terminated)]
18:06:46.580 pjsua_app.c .....Call 0 disconnected, dumping media stats..
18:06:46.580 pjsua_app_comm .....
[DISCONNCTD] To: sip:4743@172.30.38.20;tag=a747f750afce40c6
Call time: 00h:00m:00s, 1st res in 8822 ms, conn in 0ms
18:06:46.580 pjsua_media.c .....Call 0: deinitializing media..
18:06:46.580 pjsua_media.c ......Call 0: cleaning up provisional media, prov_med_cnt=1, med_cnt=0
18:06:46.582 dlg0x153fe664 .....Session count dec to 1 by mod-invite
18:06:46.582 tdta0x15403800 ..Destroying txdata Request msg INVITE/cseq=29600 (tdta0x15403800)
18:06:46.582 tsx0x14c4ea64 Timeout timer event
18:06:46.582 tsx0x14c4ea64 .State changed from Completed to Terminated, event=TIMER
18:06:46.582 dlg0x153fe664 ..Transaction tsx0x14c4ea64 state changed to Terminated
18:06:46.586 tsx0x15405864 Timeout timer event
18:06:46.586 tsx0x15405864 .State changed from Completed to Terminated, event=TIMER
18:06:46.586 dlg0x153fe664 ..Transaction tsx0x15405864 state changed to Terminated
18:06:46.586 dlg0x153fe664 ...Dialog destroyed
18:06:46.590 tsx0x14c4ea64 Timeout timer event
18:06:46.591 tsx0x14c4ea64 .State changed from Terminated to Destroyed, event=TIMER
18:06:46.591 tdta0x14c51400 ..Destroying txdata Request msg CANCEL/cseq=29600 (tdta0x14c51400)
18:06:46.591 tsx0x14c4ea64 Transaction destroyed!
18:06:46.591 tsx0x15405864 Timeout timer event
18:06:46.591 tsx0x15405864 .State changed from Terminated to Destroyed, event=TIMER
18:06:46.591 tdta0x14c54400 ..Destroying txdata Request msg ACK/cseq=29600 (tdta0x14c54400)
18:06:46.591 tsx0x15405864 Transaction destroyed!
18:06:47.580 pjsua_aud.c Closing sound device after idle for 1 second(s)
18:06:47.581 pjsua_app.c .Turning sound device OFF
18:06:47.584 pjsua_aud.c .Closing iPhone IO device sound playback device and iPhone IO device sound capture device
18:06:47.637 coreaudio_dev. .core audio stream stopped
