Hi all, For my master thesis I'm trying to use the pjsip libraries for incorperated inside my own software project. But I can't seem to be able to get pjsua working. Something clearly is going wrong, but I have no idea what the problem seems to be. If I check the sound quality paramaters during a call, I can see that I am not transmitting any sound packets, but also, I can't hear any sound that clearly is received. I did all the steps mentioned here: https://trac.pjsip.org/repos/wiki/Audio_Problems/Getting_Around_Nat but without succes. I also checked that my audio device is working by doing the command cc 0 0 to echo my microphone input sound to my output. Pjsua is initialized like this: ./pjsua-arm-unknown-linux-gnueabihf --clock-rate=48000 --capture-dev=0 --playback-dev=0 --use-ice --id=sip:XXX at sip.antisip.com --registrar=sip:sip.antisip.com --realm=* --username=XXX --password=*** --stun-srv=stun.pjsip.org --no-vad I think that the most important output is this: 15:10:06.492 pjsua_app_comm ! [CONFIRMED] To: <sip:XXX at sip.antisip.com>;tag=kiGDpg9qCdBHKMLgabtKNN1RR-6zUtNP Call time: 00h:00m:08s, 1st res in 7505 ms, conn in 7779ms #0 audio PCMU @8kHz, sendrecv, peer=91.121.78.130:51526 SRTP status: Not active Crypto-suite: ICE role: Controlled, state: Negotiation Success, comp_cnt: 2 [0]: L:192.168.1.124:4015 (h) --> R:192.168.1.110:4033 (h) [1]: L:192.168.1.124:4001 (h) --> R:192.168.1.110:4024 (h) RX pt=0, last update:00h:00m:08.808s ago total 449pkt 71.8KB (89.8KB +IP hdr) @avg=62.8Kbps/78.5Kbps pkt loss=0 (0.0%), discrd=0 (0.0%), dup=0 (0.0%), reord=0 (0.0%) (msec) min avg max last dev loss period: 0.000 0.000 0.000 0.000 0.000 jitter : 0.000 2.247 9.250 0.750 1.971 TX pt=0, ptime=20, last update:00h:00m:04.429s ago total 8pkt 1.2KB (1.6KB +IP hdr) @avg=1.1Kbps/1.3Kbps pkt loss=0 (0.0%), dup=0 (0.0%), reorder=0 (0.0%) (msec) min avg max last dev loss period: 0.000 0.000 0.000 0.000 0.000 jitter : 0.000 0.000 0.000 0.000 0.000 RTT msec : 4.425 4.425 4.425 4.425 0.000 I included the full log of the call in attachment. Thanks for your help -------------- next part -------------- An HTML attachment was scrubbed... URL: <http://lists.pjsip.org/pipermail/pjsip_lists.pjsip.org/attachments/20150303/cfe5c50d/attachment.html> -------------- next part -------------- 15:09:31.522 sip_endpoint.c .Module "mod-pjsua-log" registered 15:09:31.524 sip_endpoint.c .Module "mod-tsx-layer" registered 15:09:31.525 sip_endpoint.c .Module "mod-stateful-util" registered 15:09:31.526 sip_endpoint.c .Module "mod-ua" registered 15:09:31.527 sip_endpoint.c .Module "mod-100rel" registered 15:09:31.530 sip_endpoint.c .Module "mod-pjsua" registered 15:09:31.531 sip_endpoint.c .Module "mod-invite" registered 15:09:31.532 pjsua_core.c .Trying STUN server stun.pjsip.org (1 of 1).. 15:09:31.549 stunresolve ..TX 36 bytes STUN message to 208.109.222.137:3478: --- begin STUN message --- STUN Binding request Hdr: length=16, magic=2112a442, tsx_id=4a3b7a53cad754a800010d8c Attributes: SOFTWARE: length=12, value="pjnath-2.3.0" --- end of STUN message --- 15:09:31.549 utsx0xa20fe4 ..STUN client transaction created 15:09:31.549 utsx0xa20fe4 ..STUN sending message (transmit count=1) 15:09:31.905 pa_dev.c ..PortAudio sound library initialized, status=0 15:09:31.906 pa_dev.c ..PortAudio host api count=1 15:09:31.907 pa_dev.c ..Sound device count=10 15:09:31.909 pjlib ..select() I/O Queue created (0xa452e4) 15:09:31.911 conference.c ..Creating conference bridge with 254 ports 15:09:31.912 Master/sound ..Using delay buffer with WSOLA. 15:09:31.976 sip_endpoint.c .Module "mod-evsub" registered 15:09:31.977 sip_endpoint.c .Module "mod-presence" registered 15:09:31.978 evsub.c .Event pkg "presence" registered by mod-presence 15:09:31.978 sip_endpoint.c .Module "mod-mwi" registered 15:09:31.979 evsub.c .Event pkg "message-summary" registered by mod-mwi 15:09:31.979 sip_endpoint.c .Module "mod-refer" registered 15:09:31.980 evsub.c .Event pkg "refer" registered by mod-refer 15:09:31.980 sip_endpoint.c .Module "mod-pjsua-pres" registered 15:09:31.981 sip_endpoint.c .Module "mod-pjsua-im" registered 15:09:31.983 sip_endpoint.c .Module "mod-pjsua-options" registered 15:09:31.984 pjsua_core.c .1 SIP worker threads created 15:09:31.986 pjsua_core.c .pjsua version 2.3 for Linux-3.12.28/armv6l/glibc-2.13 initialized 15:09:31.987 pjsua_core.c .PJSUA state changed: CREATED --> INIT 15:09:31.988 sip_endpoint.c Module "mod-default-handler" registered 15:09:31.989 utsx0xa20fe4 !STUN sending message (transmit count=2) 15:09:31.990 stun_msg.c .Unrecognized attribute type 0x8020 15:09:31.990 stunresolve .RX 88 bytes STUN message from 208.109.222.137:3478: --- begin STUN message --- STUN Binding success response Hdr: length=68, magic=2112a442, tsx_id=4a3b7a53cad754a800010d8c Attributes: MAPPED-ADDRESS: length=8, IPv4 addr=81.82.213.187:49665 SOURCE-ADDRESS: length=8, IPv4 addr=208.109.222.137:3479 CHANGED-ADDRESS: length=8, IPv4 addr=208.109.222.148:3478 Attr 0x8020: length=8 SOFTWARE: length=16, value="Vovida.org 0.96" --- end of STUN message --- 15:09:31.991 stunresolve .STUN mapped address found/changed: 81.82.213.187:49665 15:09:31.994 stunresolve .STUN sock 0xa1e444 request, ref_cnt=8 15:09:31.994 stunresolve .STUN session 0xa1f66c destroy request, ref_cnt=8 15:09:31.994 utsx0xa20fe4 .STUN client transaction 0xa20fe4 stopped, ref_cnt=9 15:09:31.995 pjsua_core.c .STUN resolution success, using stun.pjsip.org, address is 208.109.222.137:3478 15:09:32.154 stun_simple.c !Warning: unknown attr type 8020 in attr 3. Attribute was ignored. 15:09:32.154 stun_simple.c Warning: unknown attr type 8022 in attr 4. Attribute was ignored. 15:09:32.154 pjsua_core.c SIP UDP socket reachable at 81.82.213.187:5060 15:09:32.156 udp0xa4d3b0 SIP UDP transport started, published address is 81.82.213.187:5060 15:09:32.157 pjsua_acc.c Adding account: id=<sip:81.82.213.187:5060> 15:09:32.158 pjsua_acc.c .Account <sip:81.82.213.187:5060> added with id 0 15:09:32.159 stun_session.c !.tdata 0xa208f4 destroy request, force=0, tsx=0xa20fe4 15:09:32.160 utsx0xa20fe4 .STUN transaction 0xa20fe4 schedule destroy 15:09:32.160 pjsua_acc.c !Modifying accunt 0 15:09:32.161 pjsua_acc.c Acc 0: setting online status to 1.. 15:09:32.165 tcplis:5060 SIP TCP listener ready for incoming connections at 192.168.1.124:5060 15:09:32.166 pjsua_acc.c Adding account: id=<sip:192.168.1.124:5060;transport=TCP> 15:09:32.167 pjsua_acc.c .Account <sip:192.168.1.124:5060;transport=TCP> added with id 1 15:09:32.168 pjsua_acc.c Modifying accunt 1 15:09:32.169 pjsua_acc.c Acc 1: setting online status to 1.. 15:09:32.170 pjsua_acc.c Adding account: id=sip:nana_test at sip.antisip.com 15:09:32.171 pjsua_acc.c .Account sip:nana_test at sip.antisip.com added with id 2 15:09:32.172 pjsua_acc.c .Acc 2: setting registration.. 15:09:32.174 endpoint ..Request msg REGISTER/cseq=63119 (tdta0xa5ead8) created. 15:09:32.175 tsx0xa5fb44 ...Transaction created for Request msg REGISTER/cseq=63120 (tdta0xa5ead8) 15:09:32.175 tsx0xa5fb44 ..Sending Request msg REGISTER/cseq=63120 (tdta0xa5ead8) in state Null 15:09:32.175 sip_resolve.c ...DNS resolver not available, target 'sip.antisip.com:0' type=Unspecified will be resolved with getaddrinfo() 15:09:32.192 sip_resolve.c ...Target 'sip.antisip.com:0' type=Unspecified resolved to '91.121.78.130:5060' type=UDP (UDP transport) 15:09:32.192 pjsua_core.c ...TX 573 bytes Request msg REGISTER/cseq=63120 (tdta0xa5ead8) to UDP 91.121.78.130:5060: REGISTER sip:sip.antisip.com SIP/2.0 Via: SIP/2.0/UDP 81.82.213.187:5060;rport;branch=z9hG4bKPj7bxORxJybrCCPrUPtQgjT7gsrUmIbsug Max-Forwards: 70 From: <sip:nana_test@xxxxxxxxxxxxxxx>;tag=i0tESjCkuCR1m5YUkvgQ5dGFn7DImn0. To: <sip:nana_test at sip.antisip.com> Call-ID: rBogR9HVIRzhmS7orvndYmQcW8QnXcRQ CSeq: 63120 REGISTER User-Agent: PJSUA v2.3 Linux-3.12.28/armv6l/glibc-2.13 Contact: <sip:nana_test at 81.82.213.187:5060;ob>;+sip.ice Expires: 300 Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS Content-Length: 0 --end msg-- 15:09:32.194 tsx0xa5fb44 ...State changed from Null to Calling, event=TX_MSG 15:09:32.194 pjsua_acc.c ..Acc 2: Registration sent 15:09:32.195 pjsua_acc.c Acc 2: setting online status to 1.. 15:09:32.196 pjsua_aud.c Set sound device: capture=0, playback=0 15:09:32.197 pjsua_app.c .Turning sound device ON 15:09:32.198 pjsua_aud.c .Opening sound device PCM at 48000/1/20ms 15:09:32.212 pa_dev.c ..Opened device Logitech Wireless Headset: USB Audio (hw:0,0)(ALSA)/Logitech Wireless Headset: USB Audio (hw:0,0)(ALSA) for recording and playback, sample rate=48000, ch=1, bits=16, 960 samples per frame, input latency=100 ms, output latency=140 ms 15:09:32.212 ec0xa4d7c0 ..Creating Echo suppressor 15:09:32.213 sip_endpoint.c !Processing incoming message: Response msg 401/REGISTER/cseq=63120 (rdata0xa5af4c) 15:09:32.213 pjsua_core.c .RX 497 bytes Response msg 401/REGISTER/cseq=63120 (rdata0xa5af4c) from UDP 91.121.78.130:5060: SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 81.82.213.187:5060;rport=5060;branch=z9hG4bKPj7bxORxJybrCCPrUPtQgjT7gsrUmIbsug From: <sip:nana_test@xxxxxxxxxxxxxxx>;tag=i0tESjCkuCR1m5YUkvgQ5dGFn7DImn0. To: <sip:nana_test at sip.antisip.com>;tag=778833f69a40e683fca7bc93f108d146.d637 Call-ID: rBogR9HVIRzhmS7orvndYmQcW8QnXcRQ CSeq: 63120 REGISTER WWW-Authenticate: Digest realm="sip.antisip.com", nonce="VPXSlFT1zqz8dN+9y0OpzW4d0GFzKLLm" Server: kamailio (4.1.2 (x86_64/linux)) Content-Length: 0 --end msg-- 15:09:32.214 tsx0xa5fb44 .Incoming Response msg 401/REGISTER/cseq=63120 (rdata0xa5af4c) in state Calling 15:09:32.214 tsx0xa5fb44 ..State changed from Calling to Completed, event=RX_MSG 15:09:32.215 ec0xa4d7c0 !..Using delay buffer with WSOLA. 15:09:32.215 ec0xa4d7c0 ..Echo suppressor created, clock_rate=48000, channel=1, samples per frame=960, tail length=200 ms, latency=100 ms 15:09:32.216 pa_dev.c ..Starting Logitech Wireless Headset: USB Audio (hw:0,0) stream.. 15:09:32.221 pa_dev.c ..Done, status=0 15:09:32.221 pjsua_core.c PJSUA state changed: INIT --> STARTING 15:09:32.223 tsx0xa71b3c !....Transaction created for Request msg REGISTER/cseq=63121 (tdta0xa5ead8) 15:09:32.223 tsx0xa71b3c ...Sending Request msg REGISTER/cseq=63121 (tdta0xa5ead8) in state Null 15:09:32.224 endpoint ....Request msg REGISTER/cseq=63121 (tdta0xa5ead8): skipping target resolution because address is already set 15:09:32.224 pjsua_core.c ....TX 756 bytes Request msg REGISTER/cseq=63121 (tdta0xa5ead8) to UDP 91.121.78.130:5060: REGISTER sip:sip.antisip.com SIP/2.0 Via: SIP/2.0/UDP 81.82.213.187:5060;rport;branch=z9hG4bKPjqgQIpt4b.-BkuZipS9tD.iV3kA1.jea6 Max-Forwards: 70 From: <sip:nana_test@xxxxxxxxxxxxxxx>;tag=i0tESjCkuCR1m5YUkvgQ5dGFn7DImn0. To: <sip:nana_test at sip.antisip.com> Call-ID: rBogR9HVIRzhmS7orvndYmQcW8QnXcRQ CSeq: 63121 REGISTER User-Agent: PJSUA v2.3 Linux-3.12.28/armv6l/glibc-2.13 Contact: <sip:nana_test at 81.82.213.187:5060;ob>;+sip.ice Expires: 300 Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS Authorization: Digest username="nana_test", realm="sip.antisip.com", nonce="VPXSlFT1zqz8dN+9y0OpzW4d0GFzKLLm", uri="sip:sip.antisip.com", response="43d0fbfe363fc5ebe11c052ab8a957a7" Content-Length: 0 --end msg-- 15:09:32.225 natck0xa722e0 !..Local address is 192.168.1.124:39135 15:09:32.225 natck0xa722e0 ..Server set to 208.109.222.137:3478 15:09:32.226 natck0xa722e0 ..Performing Test I: Binding request to 208.109.222.137:3478 15:09:32.226 natck0xa722e0 ...TX 28 bytes STUN message to 208.109.222.137:3478: --- begin STUN message --- STUN Binding request Hdr: length=8, magic=5cb2481b, tsx_id=26093b8117af070800000000 Attributes: CHANGE-REQUEST: length=4, value=0 (0x0) --- end of STUN message --- 15:09:32.226 utsx0xa7441c ...STUN client transaction created 15:09:32.226 utsx0xa7441c ...STUN sending message (transmit count=1) 15:09:32.228 tsx0xa71b3c !....State changed from Null to Calling, event=TX_MSG 15:09:32.229 sip_endpoint.c !.Module "mod-unsolicited-mwi" registered 15:09:32.231 pjsua_core.c .PJSUA state changed: STARTING --> RUNNING 15:09:32.232 main.c Ready: Success 15:09:32.242 pa_dev.c !Recorder thread started 15:09:32.243 ec0xa4d7c0 Prefetching.. 15:09:32.243 os_core_unix.c Info: possibly re-registering existing thread 15:09:32.244 sip_endpoint.c !Processing incoming message: Response msg 200/REGISTER/cseq=63121 (rdata0xa5af4c) 15:09:32.244 pjsua_core.c .RX 455 bytes Response msg 200/REGISTER/cseq=63121 (rdata0xa5af4c) from UDP 91.121.78.130:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 81.82.213.187:5060;rport=5060;branch=z9hG4bKPjqgQIpt4b.-BkuZipS9tD.iV3kA1.jea6 From: <sip:nana_test@xxxxxxxxxxxxxxx>;tag=i0tESjCkuCR1m5YUkvgQ5dGFn7DImn0. To: <sip:nana_test at sip.antisip.com>;tag=778833f69a40e683fca7bc93f108d146.d289 Call-ID: rBogR9HVIRzhmS7orvndYmQcW8QnXcRQ CSeq: 63121 REGISTER Contact: <sip:nana_test at 81.82.213.187:5060;ob>;expires=300 Server: kamailio (4.1.2 (x86_64/linux)) Content-Length: 0 --end msg-- 15:09:32.250 tsx0xa71b3c .Incoming Response msg 200/REGISTER/cseq=63121 (rdata0xa5af4c) in state Calling 15:09:32.251 tsx0xa71b3c ..State changed from Calling to Completed, event=RX_MSG 15:09:32.251 pjsua_acc.c ....SIP outbound status for acc 2 is not active 15:09:32.252 pjsua_acc.c ....sip:nana_test at sip.antisip.com: registration success, status=200 (OK), will re-register in 300 seconds 15:09:32.254 pa_dev.c !Player thread started 15:09:32.258 pjsua_acc.c !....Keep-alive timer started for acc 2, destination:91.121.78.130:5060, interval:15s 15:09:32.262 ec0xa4d7c0 !Prefetching.. 15:09:32.277 natck0xa722e0 !Performing Test II: Binding request with change address and port request to 208.109.222.137:3478 15:09:32.277 natck0xa722e0 .TX 28 bytes STUN message to 208.109.222.137:3478: --- begin STUN message --- STUN Binding request Hdr: length=8, magic=6b5daad6, tsx_id=0ab503b842dc954100000001 Attributes: CHANGE-REQUEST: length=4, value=6 (0x6) --- end of STUN message --- 15:09:32.277 utsx0xa74c14 .STUN client transaction created 15:09:32.277 utsx0xa74c14 .STUN sending message (transmit count=1) 15:09:32.282 ec0xa4d7c0 !Prefetching.. 15:09:32.302 ec0xa4d7c0 Prefetching.. 15:09:32.322 ec0xa4d7c0 Prefetching.. 15:09:32.327 utsx0xa7441c !STUN sending message (transmit count=2) 15:09:32.328 natck0xa722e0 Performing Test III: Binding request with change port request to 208.109.222.137:3478 15:09:32.328 natck0xa722e0 .TX 28 bytes STUN message to 208.109.222.137:3478: --- begin STUN message --- STUN Binding request Hdr: length=8, magic=66612663, tsx_id=5e6503d3612c717000000002 Attributes: CHANGE-REQUEST: length=4, value=2 (0x2) --- end of STUN message --- 15:09:32.328 utsx0xa7540c .STUN client transaction created 15:09:32.328 utsx0xa7540c .STUN sending message (transmit count=1) 15:09:32.342 ec0xa4d7c0 !Prefetching.. 15:09:32.342 ec0xa4d7c0 Latency bufferring complete 15:09:32.370 stun_msg.c !.Unrecognized attribute type 0x8020 15:09:32.371 natck0xa722e0 .RX 88 bytes STUN message from 208.109.222.137:3478: --- begin STUN message --- STUN Binding success response Hdr: length=68, magic=5cb2481b, tsx_id=26093b8117af070800000000 Attributes: MAPPED-ADDRESS: length=8, IPv4 addr=81.82.213.187:39135 SOURCE-ADDRESS: length=8, IPv4 addr=208.109.222.137:3479 CHANGED-ADDRESS: length=8, IPv4 addr=208.109.222.148:3478 Attr 0x8020: length=8 SOFTWARE: length=16, value="Vovida.org 0.96" --- end of STUN message --- 15:09:32.371 natck0xa722e0 .Completed Test I: Binding request, status=0 15:09:32.371 stun_session.c .tdata 0xa73d44 destroy request, force=0, tsx=0xa7441c 15:09:32.371 utsx0xa7441c .STUN transaction 0xa7441c schedule destroy 15:09:32.378 utsx0xa74c14 STUN sending message (transmit count=2) 15:09:32.428 utsx0xa7540c STUN sending message (transmit count=2) 15:09:32.459 utsx0xa20fe4 STUN client transaction 0xa20fe4 stopped, ref_cnt=1 15:09:32.460 stun_session.c STUN transaction 0xa20fe4 destroyed 15:09:32.460 STUN sock 0xa1e444 destroyed 15:09:32.460 stun_session.c STUN session 0xa1f66c destroyed 15:09:32.472 stun_msg.c .Unrecognized attribute type 0x8020 15:09:32.472 natck0xa722e0 .RX 88 bytes STUN message from 208.109.222.137:3478: --- begin STUN message --- STUN Binding success response Hdr: length=68, magic=5cb2481b, tsx_id=26093b8117af070800000000 Attributes: MAPPED-ADDRESS: length=8, IPv4 addr=81.82.213.187:39135 SOURCE-ADDRESS: length=8, IPv4 addr=208.109.222.137:3479 CHANGED-ADDRESS: length=8, IPv4 addr=208.109.222.148:3478 Attr 0x8020: length=8 SOFTWARE: length=16, value="Vovida.org 0.96" --- end of STUN message --- 15:09:32.472 stun_msg.c .Unrecognized attribute type 0x8020 15:09:32.473 natck0xa722e0 .RX 88 bytes STUN message from 208.109.222.137:3479: --- begin STUN message --- STUN Binding success response Hdr: length=68, magic=66612663, tsx_id=5e6503d3612c717000000002 Attributes: MAPPED-ADDRESS: length=8, IPv4 addr=81.82.213.187:39135 SOURCE-ADDRESS: length=8, IPv4 addr=208.109.222.137:3478 CHANGED-ADDRESS: length=8, IPv4 addr=208.109.222.148:3478 Attr 0x8020: length=8 SOFTWARE: length=16, value="Vovida.org 0.96" --- end of STUN message --- 15:09:32.473 natck0xa722e0 .Completed Test III: Binding request with change port request, status=0 15:09:32.473 stun_session.c .tdata 0xa74d34 destroy request, force=0, tsx=0xa7540c 15:09:32.473 utsx0xa7540c .STUN transaction 0xa7540c schedule destroy 15:09:32.578 utsx0xa74c14 STUN sending message (transmit count=3) 15:09:32.580 stun_msg.c .Unrecognized attribute type 0x8020 15:09:32.580 natck0xa722e0 .RX 88 bytes STUN message from 208.109.222.137:3479: --- begin STUN message --- STUN Binding success response Hdr: length=68, magic=66612663, tsx_id=5e6503d3612c717000000002 Attributes: MAPPED-ADDRESS: length=8, IPv4 addr=81.82.213.187:39135 SOURCE-ADDRESS: length=8, IPv4 addr=208.109.222.137:3478 CHANGED-ADDRESS: length=8, IPv4 addr=208.109.222.148:3478 Attr 0x8020: length=8 SOFTWARE: length=16, value="Vovida.org 0.96" --- end of STUN message --- 15:09:32.671 utsx0xa7441c STUN client transaction 0xa7441c stopped, ref_cnt=6 15:09:32.671 stun_session.c STUN transaction 0xa7441c destroyed 15:09:32.774 utsx0xa7540c STUN client transaction 0xa7540c stopped, ref_cnt=5 15:09:32.774 stun_session.c STUN transaction 0xa7540c destroyed 15:09:32.978 utsx0xa74c14 STUN sending message (transmit count=4) 15:09:33.225 pjsua_aud.c Closing sound device after idle for 1 second(s) 15:09:33.226 pjsua_app.c .Turning sound device OFF 15:09:33.227 pjsua_aud.c .Closing Logitech Wireless Headset: USB Audio (hw:0,0) sound playback device and Logitech Wireless Headset: USB Audio (hw:0,0) sound capture device 15:09:34.260 pa_dev.c .Stopping stream.. 15:09:34.261 pa_dev.c .Done, status=0 15:09:34.370 pa_dev.c .Closing Logitech Wireless Headset: USB Audio (hw:0,0): 0 underflow, 0 overflow 15:09:34.385 utsx0xa74c14 STUN sending message (transmit count=5) 15:09:35.984 utsx0xa74c14 STUN sending message (transmit count=6) 15:09:37.229 tsx0xa5fb44 Timeout timer event 15:09:37.229 tsx0xa5fb44 .State changed from Completed to Terminated, event=TIMER 15:09:37.230 tsx0xa5fb44 Timeout timer event 15:09:37.230 tsx0xa5fb44 .State changed from Terminated to Destroyed, event=TIMER 15:09:37.231 tsx0xa5fb44 Transaction destroyed! 15:09:37.250 tsx0xa71b3c Timeout timer event 15:09:37.250 tsx0xa71b3c .State changed from Completed to Terminated, event=TIMER 15:09:37.250 tsx0xa71b3c Timeout timer event 15:09:37.250 tsx0xa71b3c .State changed from Terminated to Destroyed, event=TIMER 15:09:37.251 tdta0xa5ead8 ..Destroying txdata Request msg REGISTER/cseq=63121 (tdta0xa5ead8) 15:09:37.251 tsx0xa71b3c Transaction destroyed! 15:09:39.185 utsx0xa74c14 STUN sending message (transmit count=7) 15:09:40.785 utsx0xa74c14 STUN timeout waiting for response 15:09:40.786 natck0xa722e0 .Completed Test II: Binding request with change address and port request, status=370004 15:09:40.786 natck0xa722e0 .Performing Test IB: Binding request to alternate address to 208.109.222.148:3478 15:09:40.787 natck0xa722e0 ..TX 28 bytes STUN message to 208.109.222.148:3478: --- begin STUN message --- STUN Binding request Hdr: length=8, magic=678e3615, tsx_id=11a009754d0325cf00000003 Attributes: CHANGE-REQUEST: length=4, value=0 (0x0) --- end of STUN message --- 15:09:40.787 utsx0xa5e1ec ..STUN client transaction created 15:09:40.787 utsx0xa5e1ec ..STUN sending message (transmit count=1) 15:09:40.787 stun_session.c .tdata 0xa7453c destroy request, force=1, tsx=0xa74c14 15:09:40.787 utsx0xa74c14 .STUN client transaction 0xa74c14 stopped, ref_cnt=7 15:09:40.886 utsx0xa5e1ec STUN sending message (transmit count=2) 15:09:41.087 utsx0xa5e1ec STUN sending message (transmit count=3) 15:09:41.487 utsx0xa5e1ec STUN sending message (transmit count=4) 15:09:42.286 utsx0xa5e1ec STUN sending message (transmit count=5) 15:09:43.886 utsx0xa5e1ec STUN sending message (transmit count=6) 15:09:47.086 utsx0xa5e1ec STUN sending message (transmit count=7) 15:09:47.258 pjsua_acc.c Sending 2 bytes keep-alive packet for acc 2 to 91.121.78.130:5060 15:09:47.258 tdta0xa1e328 Destroying txdata raw 15:09:48.686 utsx0xa5e1ec STUN timeout waiting for response 15:09:48.687 natck0xa722e0 .Completed Test IB: Binding request to alternate address, status=370004 15:09:48.687 pjsua_app.c .NAT detected as Restricted 15:09:48.688 stun_session.c .tdata 0xa1ad44 destroy request, force=1, tsx=0xa5e1ec 15:09:48.688 utsx0xa5e1ec .STUN client transaction 0xa5e1ec stopped, ref_cnt=6 15:09:48.691 natck0xa722e0 STUN session 0xa73114 destroy request, ref_cnt=2 15:09:48.691 stun_session.c STUN session 0xa73114 destroyed 15:09:49.795 sip_endpoint.c Processing incoming message: Request msg INVITE/cseq=16940 (rdata0xa5af4c) 15:09:49.796 pjsua_core.c .RX 1995 bytes Request msg INVITE/cseq=16940 (rdata0xa5af4c) from UDP 91.121.78.130:5060: INVITE sip:nana_test at 81.82.213.187:5060;ob SIP/2.0 Record-Route: <sip:91.121.78.130;r2=on;lr;frc=yes;mr=yes> Record-Route: <sip:91.121.78.130;transport=tcp;r2=on;lr;frc=yes;mr=yes> Via: SIP/2.0/UDP 91.121.78.130;branch=z9hG4bKfaea.5150906f6ed7bfa7c0319eaa5f35314e.0;i=7ee Via: SIP/2.0/TCP 192.168.1.110:32866;received=81.82.213.187;rport=32866;branch=z9hG4bKPjg.lsT4y8WcahMQLwU8j9a8HHgfrNTPq2;alias Max-Forwards: 16 From: sip:david_test@xxxxxxxxxxxxxxx;tag=kiGDpg9qCdBHKMLgabtKNN1RR-6zUtNP To: sip:nana_test at sip.antisip.com Contact: <sip:david_test at 81.82.213.187:55180;alias=81.82.213.187~32866~2;ob>;+sip.ice Call-ID: J8G4AP209IQgmOFQgzCN6.3oBr1724L0 CSeq: 16940 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 User-Agent: PJSUA v2.3 Linux-3.13.0.46/x86_64/glibc-2.19 Content-Type: application/sdp Content-Length: 991 P-PMR: mediarelay enabled v=0 o=- 3634384189 3634384189 IN IP4 91.121.78.130 s=pjmedia b=AS:84 t=0 0 a=X-nat:0 m=audio 51526 RTP/AVP 98 97 99 104 3 0 8 9 96 c=IN IP4 91.121.78.130 b=TIAS:64000 a=rtcp:51527 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 a=ice-ufrag:181ccc16 a=ice-pwd:01ad9069 a=candidate:Sc0a8016e 1 UDP 1862270975 81.82.213.187 4033 typ srflx raddr 192.168.1.110 rport 4033 a=candidate:Hc0a8016e 1 UDP 1694498815 192.168.1.110 4033 typ host a=candidate:Sc0a8016e 2 UDP 1862270974 81.82.213.187 4024 typ srflx raddr 192.168.1.110 rport 4024 a=candidate:9112178130 2 UDP 16777214 91.121.78.130 51527 typ relay a=candidate:9112178130 1 UDP 16777215 91.121.78.130 51526 typ relay a=candidate:Hc0a8016e 2 UDP 1694498814 192.168.1.110 4024 typ host a=nortpproxy:yes --end msg-- 15:09:49.802 pjsua_call.c .Incoming Request msg INVITE/cseq=16940 (rdata0xa5af4c) 15:09:49.804 tsx0xa1eb94 ...Transaction created for Request msg INVITE/cseq=16940 (rdata0xa5af4c) 15:09:49.805 tsx0xa1eb94 ..Incoming Request msg INVITE/cseq=16940 (rdata0xa5af4c) in state Null 15:09:49.805 tsx0xa1eb94 ...State changed from Null to Trying, event=RX_MSG 15:09:49.805 dlg0xa1e38c ....Transaction tsx0xa1eb94 state changed to Trying 15:09:49.805 dlg0xa1e38c ..UAS dialog created 15:09:49.805 dlg0xa1e38c ..Module mod-invite added as dialog usage, data=0xa20cb4 15:09:49.805 dlg0xa1e38c ...Session count inc to 2 by mod-invite 15:09:49.806 inv0xa1e38c ..UAS invite session created for dialog dlg0xa1e38c 15:09:49.806 pjsua_media.c ..Call 0: initializing media.. 15:09:49.807 icetp00 ...Creating ICE stream transport with 2 component(s) 15:09:49.808 icetp00 ....Comp 1: srflx candidate starts Binding discovery 15:09:49.810 stuntp0xa5fa10 ......TX 36 bytes STUN message to 208.109.222.137:3478: --- begin STUN message --- STUN Binding request Hdr: length=16, magic=2112a442, tsx_id=4ce461f56b6b0d2b000172b3 Attributes: SOFTWARE: length=12, value="pjnath-2.3.0" --- end of STUN message --- 15:09:49.810 utsx0xa61e6c ......STUN client transaction created 15:09:49.810 utsx0xa61e6c ......STUN sending message (transmit count=1) 15:09:49.815 icetp00 ....Comp 1: host candidate 192.168.1.124:4015 added 15:09:49.816 icetp00 ....Comp 2: srflx candidate starts Binding discovery 15:09:49.818 stuntp0xa62318 ......TX 36 bytes STUN message to 208.109.222.137:3478: --- begin STUN message --- STUN Binding request Hdr: length=16, magic=2112a442, tsx_id=25e8bd64746286cc00012574 Attributes: SOFTWARE: length=12, value="pjnath-2.3.0" --- end of STUN message --- 15:09:49.818 utsx0xa64774 ......STUN client transaction created 15:09:49.818 utsx0xa64774 ......STUN sending message (transmit count=1) 15:09:49.822 icetp00 ....Comp 2: host candidate 192.168.1.124:4001 added 15:09:49.823 icetp00 ....ICE stream transport 0xa5f05c created 15:09:49.824 pjsua_media.c ...Media index 0 selected for audio call 0 15:09:49.825 pjsua_call.c ..Call 0: remote NAT type is 0 (Unknown) 15:09:49.826 endpoint ...Response msg 100/INVITE/cseq=16940 (tdta0xa64818) created 15:09:49.826 dlg0xa1e38c ...Initial answer Response msg 100/INVITE/cseq=16940 (tdta0xa64818) 15:09:49.826 inv0xa1e38c ...Sending Response msg 100/INVITE/cseq=16940 (tdta0xa64818) 15:09:49.827 dlg0xa1e38c ....Sending Response msg 100/INVITE/cseq=16940 (tdta0xa64818) 15:09:49.827 tsx0xa1eb94 ....Sending Response msg 100/INVITE/cseq=16940 (tdta0xa64818) in state Trying 15:09:49.827 sip_resolve.c .....Target '91.121.78.130:5060' type=UDP resolved to '91.121.78.130:5060' type=UDP (UDP transport) 15:09:49.827 pjsua_core.c .....TX 594 bytes Response msg 100/INVITE/cseq=16940 (tdta0xa64818) to UDP 91.121.78.130:5060: SIP/2.0 100 Trying Via: SIP/2.0/UDP 91.121.78.130;received=91.121.78.130;branch=z9hG4bKfaea.5150906f6ed7bfa7c0319eaa5f35314e.0;i=7ee Via: SIP/2.0/TCP 192.168.1.110:32866;rport=32866;received=81.82.213.187;branch=z9hG4bKPjg.lsT4y8WcahMQLwU8j9a8HHgfrNTPq2;alias Record-Route: <sip:91.121.78.130;lr;r2=on;frc=yes;mr=yes> Record-Route: <sip:91.121.78.130;transport=tcp;lr;r2=on;frc=yes;mr=yes> Call-ID: J8G4AP209IQgmOFQgzCN6.3oBr1724L0 From: <sip:david_test@xxxxxxxxxxxxxxx>;tag=kiGDpg9qCdBHKMLgabtKNN1RR-6zUtNP To: <sip:nana_test at sip.antisip.com> CSeq: 16940 INVITE Content-Length: 0 --end msg-- 15:09:49.829 tsx0xa1eb94 .....State changed from Trying to Proceeding, event=TX_MSG 15:09:49.829 dlg0xa1e38c ......Transaction tsx0xa1eb94 state changed to Proceeding 15:09:49.829 pjsua_aud.c ..Conf connect: 2 --> 0 15:09:49.830 pjsua_aud.c ...Set sound device: capture=0, playback=0 15:09:49.832 pjsua_app.c ....Turning sound device ON 15:09:49.833 pjsua_aud.c ....Opening sound device PCM at 48000/1/20ms 15:09:49.845 pa_dev.c .....Opened device Logitech Wireless Headset: USB Audio (hw:0,0)(ALSA)/Logitech Wireless Headset: USB Audio (hw:0,0)(ALSA) for recording and playback, sample rate=48000, ch=1, bits=16, 960 samples per frame, input latency=100 ms, output latency=140 ms 15:09:49.846 ec0xa6b108 .....Creating Echo suppressor 15:09:49.846 ec0xa6b108 .....Using delay buffer with WSOLA. 15:09:49.846 ec0xa6b108 .....Echo suppressor created, clock_rate=48000, channel=1, samples per frame=960, tail length=200 ms, latency=100 ms 15:09:49.847 pa_dev.c .....Starting Logitech Wireless Headset: USB Audio (hw:0,0) stream.. 15:09:49.852 pa_dev.c .....Done, status=0 15:09:49.852 conference.c ...Port 2 (ring) transmitting to port 0 (Logitech Wireless Headset: USB Audio (hw:0,0)) 15:09:49.853 pjsua_app.c ..Incoming call for account 2! Media count: 1 audio & 0 video From: <sip:david_test@xxxxxxxxxxxxxxx> To: <sip:nana_test at sip.antisip.com> Press a to answer or h to reject call 15:09:49.873 pa_dev.c !Recorder thread started 15:09:49.873 ec0xa6b108 Prefetching.. 15:09:49.873 os_core_unix.c Info: possibly re-registering existing thread 15:09:49.874 pa_dev.c !Player thread started 15:09:49.893 ec0xa6b108 Prefetching.. 15:09:49.911 utsx0xa61e6c !STUN sending message (transmit count=2) 15:09:49.913 ec0xa6b108 !Prefetching.. 15:09:49.919 utsx0xa64774 !STUN sending message (transmit count=2) 15:09:49.933 ec0xa6b108 !Prefetching.. 15:09:49.950 stun_msg.c !.Unrecognized attribute type 0x8020 15:09:49.951 stuntp0xa5fa10 .RX 88 bytes STUN message from 208.109.222.137:3478: --- begin STUN message --- STUN Binding success response Hdr: length=68, magic=2112a442, tsx_id=4ce461f56b6b0d2b000172b3 Attributes: MAPPED-ADDRESS: length=8, IPv4 addr=81.82.213.187:4015 SOURCE-ADDRESS: length=8, IPv4 addr=208.109.222.137:3479 CHANGED-ADDRESS: length=8, IPv4 addr=208.109.222.148:3478 Attr 0x8020: length=8 SOFTWARE: length=16, value="Vovida.org 0.96" --- end of STUN message --- 15:09:49.951 stuntp0xa5fa10 .STUN mapped address found/changed: 81.82.213.187:4015 15:09:49.955 icetp00 .Comp 1: Binding discovery complete, srflx address is 81.82.213.187:4015 15:09:49.957 ec0xa6b108 !Prefetching.. 15:09:49.962 stun_session.c !.tdata 0xa6177c destroy request, force=0, tsx=0xa61e6c 15:09:49.963 utsx0xa61e6c .STUN transaction 0xa61e6c schedule destroy 15:09:49.965 stun_msg.c .Unrecognized attribute type 0x8020 15:09:49.966 stuntp0xa62318 .RX 88 bytes STUN message from 208.109.222.137:3478: --- begin STUN message --- STUN Binding success response Hdr: length=68, magic=2112a442, tsx_id=25e8bd64746286cc00012574 Attributes: MAPPED-ADDRESS: length=8, IPv4 addr=81.82.213.187:4001 SOURCE-ADDRESS: length=8, IPv4 addr=208.109.222.137:3479 CHANGED-ADDRESS: length=8, IPv4 addr=208.109.222.148:3478 Attr 0x8020: length=8 SOFTWARE: length=16, value="Vovida.org 0.96" --- end of STUN message --- 15:09:49.966 stuntp0xa62318 .STUN mapped address found/changed: 81.82.213.187:4001 15:09:49.970 icetp00 .Comp 2: Binding discovery complete, srflx address is 81.82.213.187:4001 15:09:49.971 stun_session.c .tdata 0xa64084 destroy request, force=0, tsx=0xa64774 15:09:49.971 utsx0xa64774 .STUN transaction 0xa64774 schedule destroy 15:09:49.973 ec0xa6b108 !Prefetching.. 15:09:49.977 ec0xa6b108 Latency bufferring complete 15:09:49.978 icetp00 !ICE session created, comp_cnt=2, role is Controlled agent 15:09:49.980 icetp00 ICE nomination type set to aggressive 15:09:49.981 icetp00 Candidate 0 added: comp_id=1, type=srflx, foundation=Sc0a8017c, addr=81.82.213.187:4015, base=192.168.1.124:4015, prio=0x6effffff (1862270975) 15:09:49.983 icetp00 Candidate 1 added: comp_id=1, type=host, foundation=Hc0a8017c, addr=192.168.1.124:4015, base=192.168.1.124:4015, prio=0x64ffffff (1694498815) 15:09:49.985 icetp00 Candidate 2 added: comp_id=2, type=srflx, foundation=Sc0a8017c, addr=81.82.213.187:4001, base=192.168.1.124:4001, prio=0x6efffffe (1862270974) 15:09:49.986 icetp00 Candidate 3 added: comp_id=2, type=host, foundation=Hc0a8017c, addr=192.168.1.124:4001, base=192.168.1.124:4001, prio=0x64fffffe (1694498814) 15:09:49.990 icetp00 Processing SDP: support ICE=1, common comp_cnt=2, ice_mismatch=0, ice_restart=0, local_role=Controlled 15:09:50.060 stun_msg.c .Unrecognized attribute type 0x8020 15:09:50.061 stuntp0xa5fa10 .RX 88 bytes STUN message from 208.109.222.137:3478: --- begin STUN message --- STUN Binding success response Hdr: length=68, magic=2112a442, tsx_id=4ce461f56b6b0d2b000172b3 Attributes: MAPPED-ADDRESS: length=8, IPv4 addr=81.82.213.187:4015 SOURCE-ADDRESS: length=8, IPv4 addr=208.109.222.137:3479 CHANGED-ADDRESS: length=8, IPv4 addr=208.109.222.148:3478 Attr 0x8020: length=8 SOFTWARE: length=16, value="Vovida.org 0.96" --- end of STUN message --- 15:09:50.070 stun_msg.c .Unrecognized attribute type 0x8020 15:09:50.070 stuntp0xa62318 .RX 88 bytes STUN message from 208.109.222.137:3478: --- begin STUN message --- STUN Binding success response Hdr: length=68, magic=2112a442, tsx_id=25e8bd64746286cc00012574 Attributes: MAPPED-ADDRESS: length=8, IPv4 addr=81.82.213.187:4001 SOURCE-ADDRESS: length=8, IPv4 addr=208.109.222.137:3479 CHANGED-ADDRESS: length=8, IPv4 addr=208.109.222.148:3478 Attr 0x8020: length=8 SOFTWARE: length=16, value="Vovida.org 0.96" --- end of STUN message --- 15:09:50.263 utsx0xa61e6c STUN client transaction 0xa61e6c stopped, ref_cnt=14 15:09:50.263 stun_session.c STUN transaction 0xa61e6c destroyed 15:09:50.272 utsx0xa64774 STUN client transaction 0xa64774 stopped, ref_cnt=13 15:09:50.272 stun_session.c STUN transaction 0xa64774 destroyed 15:09:57.306 pjsua_call.c !Answering call 0: code=200 15:09:57.309 inv0xa1e38c ..SDP negotiation done, status=0 15:09:57.309 pjsua_call.c ...Call 0: remote NAT type is 0 (Unknown) 15:09:57.309 pjsua_media.c ...Call 0: updating media.. 15:09:57.313 icetp00 ....Check 2: [1] 192.168.1.124:4015-->81.82.213.187:4033 pruned (duplicate found) 15:09:57.317 icetp00 ....Check 4: [2] 192.168.1.124:4001-->81.82.213.187:4024 pruned (duplicate found) 15:09:57.318 icetp00 ....Check 3: [1] 192.168.1.124:4015-->192.168.1.110:4033 pruned (duplicate found) 15:09:57.319 icetp00 ....Check 4: [2] 192.168.1.124:4001-->192.168.1.110:4024 pruned (duplicate found) 15:09:57.321 icetp00 ....Check 5: [1] 192.168.1.124:4015-->91.121.78.130:51526 pruned (duplicate found) 15:09:57.322 icetp00 ....Check 6: [2] 192.168.1.124:4001-->91.121.78.130:51527 pruned (duplicate found) 15:09:57.324 icetp00 ....Checklist created: 15:09:57.325 icetp00 .... 0: [1] 192.168.1.124:4015-->81.82.213.187:4033 (not nominated, state=Frozen) 15:09:57.327 icetp00 .... 1: [2] 192.168.1.124:4001-->81.82.213.187:4024 (not nominated, state=Frozen) 15:09:57.329 icetp00 .... 2: [1] 192.168.1.124:4015-->192.168.1.110:4033 (not nominated, state=Frozen) 15:09:57.330 icetp00 .... 3: [2] 192.168.1.124:4001-->192.168.1.110:4024 (not nominated, state=Frozen) 15:09:57.332 icetp00 .... 4: [1] 192.168.1.124:4015-->91.121.78.130:51526 (not nominated, state=Frozen) 15:09:57.335 icetp00 .... 5: [2] 192.168.1.124:4001-->91.121.78.130:51527 (not nominated, state=Frozen) 15:09:57.336 icetp00 ....Starting ICE check.. 15:09:57.338 icetp00 .....Check 0: [1] 192.168.1.124:4015-->81.82.213.187:4033: state changed from Frozen to Waiting 15:09:57.339 pjsua_aud.c ....Audio channel update.. 15:09:57.342 rtp.c .....pjmedia_rtp_session_init: ses=0xa82d38, default_pt=0, ssrc=0x7ce5861b 15:09:57.342 rtp.c .....pjmedia_rtp_session_init: ses=0xa833c0, default_pt=0, ssrc=0x7ce5861b 15:09:57.343 stream.c .....Stream strm0xa81274 created 15:09:57.343 strm0xa81274 .....Encoder stream started 15:09:57.344 icetp00 !Checklist: state changed from Idle to Running 15:09:57.346 icetp00 Starting checklist periodic check 15:09:57.347 icetp00 .Sending connectivity check for check 0: [1] 192.168.1.124:4015-->81.82.213.187:4033 15:09:57.350 stuse0xa7a240 ...TX 112 bytes STUN message to 81.82.213.187:4033: --- begin STUN message --- STUN Binding request Hdr: length=92, magic=2112a442, tsx_id=000009552ed09c5a0e7c55cf Attributes: PRIORITY: length=4, value=2130706431 (0x7effffff) ICE-CONTROLLED: length=8, data=482c72902ba1582b SOFTWARE: length=12, value="pjnath-2.3.0" USERNAME: length=17, value="181ccc16:20b32106" MESSAGE-INTEGRITY: length=20, data=118be1455633a2296544b93cd47300a7c652535d FINGERPRINT: length=4, value=2112628768 (0x7dec2820) --- end of STUN message --- 15:09:57.350 utsx0xa83ee8 ...STUN client transaction created 15:09:57.350 utsx0xa83ee8 ...STUN sending message (transmit count=1) 15:09:57.351 icetp00 ..Check 0: [1] 192.168.1.124:4015-->81.82.213.187:4033: state changed from Waiting to In Progress 15:09:57.352 strm0xa81274 !.....Decoder stream started 15:09:57.355 resample.c .....resample created: high qualiy, large filter, in/out rate=8000/48000 15:09:57.355 resample.c .....resample created: high qualiy, large filter, in/out rate=48000/8000 15:09:57.355 pjsua_media.c ....Audio updated, stream #0: PCMU (sendrecv) 15:09:57.357 pjsua_app.c ...Call 0 media 0 [type=audio], status is Active 15:09:57.358 pjsua_aud.c ...Conf disconnect: 2 -x- 0 15:09:57.361 conference.c ....Port 2 (ring) stop transmitting to port 0 (Logitech Wireless Headset: USB Audio (hw:0,0)) 15:09:57.362 pjsua_aud.c ...Conf connect: 3 --> 0 15:09:57.365 conference.c ....Port 3 (sip:david_test at sip.antisip.com) transmitting to port 0 (Logitech Wireless Headset: USB Audio (hw:0,0)) 15:09:57.367 pjsua_aud.c ...Conf connect: 0 --> 3 15:09:57.369 conference.c ....Port 0 (Logitech Wireless Headset: USB Audio (hw:0,0)) transmitting to port 3 (sip:david_test at sip.antisip.com) 15:09:57.370 inv0xa1e38c ..Sending Response msg 200/INVITE/cseq=16940 (tdta0xa64818) 15:09:57.371 dlg0xa1e38c ...Sending Response msg 200/INVITE/cseq=16940 (tdta0xa64818) 15:09:57.371 tsx0xa1eb94 ...Sending Response msg 200/INVITE/cseq=16940 (tdta0xa64818) in state Proceeding 15:09:57.372 pjsua_core.c ....TX 1569 bytes Response msg 200/INVITE/cseq=16940 (tdta0xa64818) to UDP 91.121.78.130:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 91.121.78.130;received=91.121.78.130;branch=z9hG4bKfaea.5150906f6ed7bfa7c0319eaa5f35314e.0;i=7ee Via: SIP/2.0/TCP 192.168.1.110:32866;rport=32866;received=81.82.213.187;branch=z9hG4bKPjg.lsT4y8WcahMQLwU8j9a8HHgfrNTPq2;alias Record-Route: <sip:91.121.78.130;lr;r2=on;frc=yes;mr=yes> Record-Route: <sip:91.121.78.130;transport=tcp;lr;r2=on;frc=yes;mr=yes> Call-ID: J8G4AP209IQgmOFQgzCN6.3oBr1724L0 From: <sip:david_test@xxxxxxxxxxxxxxx>;tag=kiGDpg9qCdBHKMLgabtKNN1RR-6zUtNP To: <sip:nana_test at sip.antisip.com>;tag=1ZizPkTBq.uBj5BhqiyUu6LNUtq4mkS- CSeq: 16940 INVITE Contact: <sip:nana_test at 81.82.213.187:5060;ob>;+sip.ice Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS Supported: replaces, 100rel, timer, norefersub Session-Expires: 1800;refresher=uac Require: timer Content-Type: application/sdp Content-Length: 652 v=0 o=- 3634384189 3634384190 IN IP4 81.82.213.187 s=pjmedia b=AS:84 t=0 0 a=X-nat:7 m=audio 4015 RTP/AVP 0 96 c=IN IP4 81.82.213.187 b=TIAS:64000 a=rtcp:4001 IN IP4 81.82.213.187 a=sendrecv a=rtpmap:0 PCMU/8000 a=rtpmap:96 telephone-event/8000 a=fmtp:96 0-16 a=ice-ufrag:20b32106 a=ice-pwd:2e0147a9 a=candidate:Sc0a8017c 1 UDP 1862270975 81.82.213.187 4015 typ srflx raddr 192.168.1.124 rport 4015 a=candidate:Hc0a8017c 1 UDP 1694498815 192.168.1.124 4015 typ host a=candidate:Sc0a8017c 2 UDP 1862270974 81.82.213.187 4001 typ srflx raddr 192.168.1.124 rport 4001 a=candidate:Hc0a8017c 2 UDP 1694498814 192.168.1.124 4001 typ host --end msg-- 15:09:57.375 strm0xa81274 !Jitter buffer is bufferring (prefetch=0), plc invoked 15:09:57.390 tsx0xa1eb94 !....State changed from Proceeding to Completed, event=TX_MSG 15:09:57.390 dlg0xa1e38c .....Transaction tsx0xa1eb94 state changed to Completed 15:09:57.393 pjsua_app.c .......Call 0 state changed to CONNECTING 15:09:57.405 icetp00 !Starting checklist periodic check 15:09:57.406 icetp00 .Sending connectivity check for check 1: [2] 192.168.1.124:4001-->81.82.213.187:4024 15:09:57.409 stuse0xa7b228 ...TX 112 bytes STUN message to 81.82.213.187:4024: --- begin STUN message --- STUN Binding request Hdr: length=92, magic=2112a442, tsx_id=0000095507947f890e7c55d0 Attributes: PRIORITY: length=4, value=2130706430 (0x7efffffe) ICE-CONTROLLED: length=8, data=482c72902ba1582b SOFTWARE: length=12, value="pjnath-2.3.0" USERNAME: length=17, value="181ccc16:20b32106" MESSAGE-INTEGRITY: length=20, data=cd8d4c1bc39fb672bf49daef48f70327994fffe1 FINGERPRINT: length=4, value=4136954941 (0xf694ec3d) --- end of STUN message --- 15:09:57.409 utsx0xa86d08 ...STUN client transaction created 15:09:57.409 utsx0xa86d08 ...STUN sending message (transmit count=1) 15:09:57.410 icetp00 ..Check 1: [2] 192.168.1.124:4001-->81.82.213.187:4024: state changed from Frozen to In Progress 15:09:57.421 stuse0xa7a240 .RX 116 bytes STUN message from 81.82.213.187:4033: --- begin STUN message --- STUN Binding request Hdr: length=96, magic=2112a442, tsx_id=00005f284a3bdab44b509962 Attributes: PRIORITY: length=4, value=2130706431 (0x7effffff) USE-CANDIDATE: length=0 ICE-CONTROLLING: length=8, data=2acc2d0a59d16092 SOFTWARE: length=12, value="pjnath-2.3.0" USERNAME: length=17, value="20b32106:181ccc16" MESSAGE-INTEGRITY: length=20, data=3f6c503307f11ffbb346f1b3789b426f0abbf8ad FINGERPRINT: length=4, value=828995612 (0x3169781c) --- end of STUN message --- 15:09:57.422 stuse0xa7a240 ..TX 80 bytes STUN message to 81.82.213.187:4033: --- begin STUN message --- STUN Binding success response Hdr: length=60, magic=2112a442, tsx_id=00005f284a3bdab44b509962 Attributes: XOR-MAPPED-ADDRESS: length=8, IPv4 addr=81.82.213.187:4033 SOFTWARE: length=12, value="pjnath-2.3.0" MESSAGE-INTEGRITY: length=20, data=1ed00e308fe7fa4b1168e89488a38dd9115f60ed FINGERPRINT: length=4, value=1180552842 (0x465dce8a) --- end of STUN message --- 15:09:57.422 icetp00 .Triggered check for check 0 not performed because it's in progress. Retransmitting 15:09:57.423 utsx0xa83ee8 ..STUN sending message (transmit count=1) 15:09:57.433 stuse0xa7b228 .RX 116 bytes STUN message from 81.82.213.187:4024: --- begin STUN message --- STUN Binding request Hdr: length=96, magic=2112a442, tsx_id=00005f2840dfde294b509963 Attributes: PRIORITY: length=4, value=2130706430 (0x7efffffe) USE-CANDIDATE: length=0 ICE-CONTROLLING: length=8, data=2acc2d0a59d16092 SOFTWARE: length=12, value="pjnath-2.3.0" USERNAME: length=17, value="20b32106:181ccc16" MESSAGE-INTEGRITY: length=20, data=68c2159883f73e13d01cc112ea1f7e50092713c7 FINGERPRINT: length=4, value=3797269409 (0xe255bba1) --- end of STUN message --- 15:09:57.434 stuse0xa7b228 ..TX 80 bytes STUN message to 81.82.213.187:4024: --- begin STUN message --- STUN Binding success response Hdr: length=60, magic=2112a442, tsx_id=00005f2840dfde294b509963 Attributes: XOR-MAPPED-ADDRESS: length=8, IPv4 addr=81.82.213.187:4024 SOFTWARE: length=12, value="pjnath-2.3.0" MESSAGE-INTEGRITY: length=20, data=276d84548ff9085f38d6ab0748e1737031f5698a FINGERPRINT: length=4, value=1380527979 (0x52492f6b) --- end of STUN message --- 15:09:57.435 icetp00 .Triggered check for check 1 not performed because it's in progress. Retransmitting 15:09:57.436 utsx0xa86d08 ..STUN sending message (transmit count=1) 15:09:57.440 icetp00 Starting checklist periodic check 15:09:57.441 icetp00 .Sending connectivity check for check 2: [1] 192.168.1.124:4015-->192.168.1.110:4033 15:09:57.443 stuse0xa7a240 ...TX 112 bytes STUN message to 192.168.1.110:4033: --- begin STUN message --- STUN Binding request Hdr: length=92, magic=2112a442, tsx_id=000009556529c8820e7c55d1 Attributes: PRIORITY: length=4, value=2130706431 (0x7effffff) ICE-CONTROLLED: length=8, data=482c72902ba1582b SOFTWARE: length=12, value="pjnath-2.3.0" USERNAME: length=17, value="181ccc16:20b32106" MESSAGE-INTEGRITY: length=20, data=be7a9216dca8cec1e18fd50ebf8b193194d8c7cb FINGERPRINT: length=4, value=2624904891 (0x9c74debb) --- end of STUN message --- 15:09:57.444 utsx0xa884f0 ...STUN client transaction created 15:09:57.444 utsx0xa884f0 ...STUN sending message (transmit count=1) 15:09:57.444 icetp00 ..Check 2: [1] 192.168.1.124:4015-->192.168.1.110:4033: state changed from Frozen to In Progress 15:09:57.450 stuse0xa7a240 .RX 80 bytes STUN message from 192.168.1.110:4033: --- begin STUN message --- STUN Binding success response Hdr: length=60, magic=2112a442, tsx_id=000009556529c8820e7c55d1 Attributes: XOR-MAPPED-ADDRESS: length=8, IPv4 addr=192.168.1.124:4015 SOFTWARE: length=12, value="pjnath-2.3.0" MESSAGE-INTEGRITY: length=20, data=8417e5ab8c41292063a40ec70268591535ebc3a2 FINGERPRINT: length=4, value=1509720785 (0x59fc82d1) --- end of STUN message --- 15:09:57.450 icetp00 .Check 2: [1] 192.168.1.124:4015-->192.168.1.110:4033 (not nominated): connectivity check SUCCESS 15:09:57.452 icetp00 .Check 2: [1] 192.168.1.124:4015-->192.168.1.110:4033: state changed from In Progress to Succeeded 15:09:57.454 icetp00 .Check 3: [2] 192.168.1.124:4001-->192.168.1.110:4024: state changed from Frozen to Waiting 15:09:57.455 icetp00 .Check 4: [1] 192.168.1.124:4015-->91.121.78.130:51526: state changed from Frozen to Waiting 15:09:57.467 strm0xa81274 !Start talksprut.. 15:09:57.467 icetp00 !.Check 5: [2] 192.168.1.124:4001-->91.121.78.130:51527: state changed from Frozen to Waiting 15:09:57.468 icetp00 .Check 2 is successful 15:09:57.470 stun_session.c .tdata 0xa883e4 destroy request, force=0, tsx=0xa884f0 15:09:57.470 utsx0xa884f0 .STUN transaction 0xa884f0 schedule destroy 15:09:57.471 stuse0xa7a240 .RX 116 bytes STUN message from 192.168.1.110:4033: --- begin STUN message --- STUN Binding request Hdr: length=96, magic=2112a442, tsx_id=00005f2841f285054b509964 Attributes: PRIORITY: length=4, value=2130706431 (0x7effffff) USE-CANDIDATE: length=0 ICE-CONTROLLING: length=8, data=2acc2d0a59d16092 SOFTWARE: length=12, value="pjnath-2.3.0" USERNAME: length=17, value="20b32106:181ccc16" MESSAGE-INTEGRITY: length=20, data=866653618196a8a3e5fdb4be7f2b3dddb8e1f8c7 FINGERPRINT: length=4, value=2181635786 (0x82091eca) --- end of STUN message --- 15:09:57.472 stuse0xa7a240 ..TX 80 bytes STUN message to 192.168.1.110:4033: --- begin STUN message --- STUN Binding success response Hdr: length=60, magic=2112a442, tsx_id=00005f2841f285054b509964 Attributes: XOR-MAPPED-ADDRESS: length=8, IPv4 addr=192.168.1.110:4033 SOFTWARE: length=12, value="pjnath-2.3.0" MESSAGE-INTEGRITY: length=20, data=b17a5a77d32df2a49aef730a53ea9f9e65ff026d FINGERPRINT: length=4, value=878573328 (0x345df710) --- end of STUN message --- 15:09:57.473 icetp00 .Valid check 0: [1] 192.168.1.124:4015-->192.168.1.110:4033 is nominated 15:09:57.474 icetp00 .Triggered check for check 2 not performed because it's completed 15:09:57.475 icetp00 ..Check 2 is successful and nominated 15:09:57.476 icetp00 ..Cancelling check 0: [1] 192.168.1.124:4015-->81.82.213.187:4033 (In Progress) 15:09:57.477 stun_session.c ..tdata 0xa83ddc destroy request, force=0, tsx=0xa83ee8 15:09:57.477 utsx0xa83ee8 ..STUN transaction 0xa83ee8 schedule destroy 15:09:57.477 icetp00 ..Check 0: [1] 192.168.1.124:4015-->81.82.213.187:4033: state changed from In Progress to Failed 15:09:57.478 icetp00 ..Check 4: [1] 192.168.1.124:4015-->91.121.78.130:51526 to be failed because state is Waiting 15:09:57.480 icetp00 ..Check 4: [1] 192.168.1.124:4015-->91.121.78.130:51526: state changed from Waiting to Failed 15:09:57.481 icetp00 Starting checklist periodic check 15:09:57.482 icetp00 .Sending connectivity check for check 3: [2] 192.168.1.124:4001-->192.168.1.110:4024 15:09:57.484 stuse0xa7b228 ...TX 112 bytes STUN message to 192.168.1.110:4024: --- begin STUN message --- STUN Binding request Hdr: length=92, magic=2112a442, tsx_id=000009557dd02fa10e7c55d2 Attributes: PRIORITY: length=4, value=2130706430 (0x7efffffe) ICE-CONTROLLED: length=8, data=482c72902ba1582b SOFTWARE: length=12, value="pjnath-2.3.0" USERNAME: length=17, value="181ccc16:20b32106" MESSAGE-INTEGRITY: length=20, data=0e1bb404e63894a550719efd9495e93f6d091369 FINGERPRINT: length=4, value=2344792408 (0x8bc2b158) --- end of STUN message --- 15:09:57.485 utsx0xa894e0 ...STUN client transaction created 15:09:57.485 utsx0xa894e0 ...STUN sending message (transmit count=1) 15:09:57.486 icetp00 ..Check 3: [2] 192.168.1.124:4001-->192.168.1.110:4024: state changed from Waiting to In Progress 15:09:57.488 stuse0xa7b228 .RX 116 bytes STUN message from 192.168.1.110:4024: --- begin STUN message --- STUN Binding request Hdr: length=96, magic=2112a442, tsx_id=00005f285397e3674b509965 Attributes: PRIORITY: length=4, value=2130706430 (0x7efffffe) USE-CANDIDATE: length=0 ICE-CONTROLLING: length=8, data=2acc2d0a59d16092 SOFTWARE: length=12, value="pjnath-2.3.0" USERNAME: length=17, value="20b32106:181ccc16" MESSAGE-INTEGRITY: length=20, data=92f470a7ebd34d62cb18f38adea40284e8c4eba3 FINGERPRINT: length=4, value=3558221226 (0xd41625aa) --- end of STUN message --- 15:09:57.488 stuse0xa7b228 ..TX 80 bytes STUN message to 192.168.1.110:4024: --- begin STUN message --- STUN Binding success response Hdr: length=60, magic=2112a442, tsx_id=00005f285397e3674b509965 Attributes: XOR-MAPPED-ADDRESS: length=8, IPv4 addr=192.168.1.110:4024 SOFTWARE: length=12, value="pjnath-2.3.0" MESSAGE-INTEGRITY: length=20, data=7316f10c34a03c09bf7efbca10f28401f03dc6e9 FINGERPRINT: length=4, value=2330747625 (0x8aec62e9) --- end of STUN message --- 15:09:57.489 icetp00 .Triggered check for check 3 not performed because it's in progress. Retransmitting 15:09:57.490 utsx0xa894e0 ..STUN sending message (transmit count=1) 15:09:57.491 stuse0xa7b228 .RX 80 bytes STUN message from 192.168.1.110:4024: --- begin STUN message --- STUN Binding success response Hdr: length=60, magic=2112a442, tsx_id=000009557dd02fa10e7c55d2 Attributes: XOR-MAPPED-ADDRESS: length=8, IPv4 addr=192.168.1.124:4001 SOFTWARE: length=12, value="pjnath-2.3.0" MESSAGE-INTEGRITY: length=20, data=a053e02c05f89e97353d3ed0ec71fcd63d1470a2 FINGERPRINT: length=4, value=2463756611 (0x92d9f143) --- end of STUN message --- 15:09:57.492 icetp00 .Check 3: [2] 192.168.1.124:4001-->192.168.1.110:4024 (nominated): connectivity check SUCCESS 15:09:57.493 icetp00 .Check 3: [2] 192.168.1.124:4001-->192.168.1.110:4024: state changed from In Progress to Succeeded 15:09:57.494 icetp00 .Check 3 is successful and nominated 15:09:57.496 icetp00 .Cancelling check 1: [2] 192.168.1.124:4001-->81.82.213.187:4024 (In Progress) 15:09:57.498 stun_session.c .tdata 0xa86bfc destroy request, force=0, tsx=0xa86d08 15:09:57.498 utsx0xa86d08 .STUN transaction 0xa86d08 schedule destroy 15:09:57.498 icetp00 .Check 1: [2] 192.168.1.124:4001-->81.82.213.187:4024: state changed from In Progress to Failed 15:09:57.500 icetp00 .Check 5: [2] 192.168.1.124:4001-->91.121.78.130:51527 to be failed because state is Waiting 15:09:57.501 icetp00 .Check 5: [2] 192.168.1.124:4001-->91.121.78.130:51527: state changed from Waiting to Failed 15:09:57.502 icetp00 .ICE process complete, status=Success 15:09:57.503 icetp00 .Valid list 15:09:57.504 icetp00 . 0: [1] 192.168.1.124:4015-->192.168.1.110:4033 (nominated, state=Succeeded) 15:09:57.505 icetp00 . 1: [2] 192.168.1.124:4001-->192.168.1.110:4024 (nominated, state=Succeeded) 15:09:57.506 stun_session.c .tdata 0xa893d4 destroy request, force=0, tsx=0xa894e0 15:09:57.506 utsx0xa894e0 .STUN transaction 0xa894e0 schedule destroy 15:09:57.506 stuse0xa7b228 .RX 116 bytes STUN message from 192.168.1.110:4024: --- begin STUN message --- STUN Binding request Hdr: length=96, magic=2112a442, tsx_id=00005f285397e3674b509965 Attributes: PRIORITY: length=4, value=2130706430 (0x7efffffe) USE-CANDIDATE: length=0 ICE-CONTROLLING: length=8, data=2acc2d0a59d16092 SOFTWARE: length=12, value="pjnath-2.3.0" USERNAME: length=17, value="20b32106:181ccc16" MESSAGE-INTEGRITY: length=20, data=92f470a7ebd34d62cb18f38adea40284e8c4eba3 FINGERPRINT: length=4, value=3558221226 (0xd41625aa) --- end of STUN message --- 15:09:57.507 stuse0xa7b228 ..TX 80 bytes STUN message to 192.168.1.110:4024: --- begin STUN message --- STUN Binding success response Hdr: length=60, magic=2112a442, tsx_id=00005f285397e3674b509965 Attributes: XOR-MAPPED-ADDRESS: length=8, IPv4 addr=192.168.1.110:4024 SOFTWARE: length=12, value="pjnath-2.3.0" MESSAGE-INTEGRITY: length=20, data=7316f10c34a03c09bf7efbca10f28401f03dc6e9 FINGERPRINT: length=4, value=2330747625 (0x8aec62e9) --- end of STUN message --- 15:09:57.508 icetp00 .Valid check 1: [2] 192.168.1.124:4001-->192.168.1.110:4024 is nominated 15:09:57.509 icetp00 .Triggered check for check 3 not performed because it's completed 15:09:57.510 icetp00 ..Check 3 is successful and nominated 15:09:57.511 stuse0xa7b228 .RX 80 bytes STUN message from 192.168.1.110:4024: --- begin STUN message --- STUN Binding success response Hdr: length=60, magic=2112a442, tsx_id=000009557dd02fa10e7c55d2 Attributes: XOR-MAPPED-ADDRESS: length=8, IPv4 addr=192.168.1.124:4001 SOFTWARE: length=12, value="pjnath-2.3.0" MESSAGE-INTEGRITY: length=20, data=a053e02c05f89e97353d3ed0ec71fcd63d1470a2 FINGERPRINT: length=4, value=2463756611 (0x92d9f143) --- end of STUN message --- 15:09:57.513 icetp00 ICE negotiation success after 0s:201 15:09:57.515 icetp00 Comp 1: sending from host candidate 192.168.1.124:4015 to host candidate 192.168.1.110:4033 15:09:57.516 icetp00 Comp 2: sending from host candidate 192.168.1.124:4001 to host candidate 192.168.1.110:4024 15:09:57.517 icetp00 Starting checklist periodic check 15:09:57.529 strm0xa81274 RTP status: badpt=0, badssrc=0, dup=0, outorder=0, probation=-1, restart=0 15:09:57.566 strm0xa81274 !Jitter buffer starts returning normal frames (after 2 empty/lost) 15:09:57.578 sip_endpoint.c !Processing incoming message: Request msg ACK/cseq=16940 (rdata0xa5af4c) 15:09:57.579 pjsua_core.c .RX 543 bytes Request msg ACK/cseq=16940 (rdata0xa5af4c) from UDP 91.121.78.130:5060: ACK sip:nana_test at 81.82.213.187:5060;ob SIP/2.0 Via: SIP/2.0/UDP 91.121.78.130;branch=z9hG4bKfaea.babb49080833984116d14fd0cf362b81.0;i=7ee Via: SIP/2.0/TCP 192.168.1.110:32866;received=81.82.213.187;rport=32866;branch=z9hG4bKPjhtSYiBuIh2NHOcGk11cWbHtj2g11uCFp;alias Max-Forwards: 16 From: sip:david_test@xxxxxxxxxxxxxxx;tag=kiGDpg9qCdBHKMLgabtKNN1RR-6zUtNP To: sip:nana_test at sip.antisip.com;tag=1ZizPkTBq.uBj5BhqiyUu6LNUtq4mkS- Call-ID: J8G4AP209IQgmOFQgzCN6.3oBr1724L0 CSeq: 16940 ACK Content-Length: 0 P-PMR: mediarelay enabled --end msg-- 15:09:57.581 dlg0xa1e38c .Received Request msg ACK/cseq=16940 (rdata0xa5af4c) 15:09:57.581 tsx0xa1eb94 ..Request to terminate transaction 15:09:57.581 tsx0xa1eb94 ...State changed from Completed to Terminated, event=USER 15:09:57.581 dlg0xa1e38c ....Transaction tsx0xa1eb94 state changed to Terminated 15:09:57.582 pjsua_app.c ...Call 0 state changed to CONFIRMED 15:09:57.591 sip_endpoint.c Processing incoming message: Request msg UPDATE/cseq=16941 (rdata0xa5af4c) 15:09:57.591 pjsua_core.c .RX 1457 bytes Request msg UPDATE/cseq=16941 (rdata0xa5af4c) from UDP 91.121.78.130:5060: UPDATE sip:nana_test at 81.82.213.187:5060;ob SIP/2.0 Via: SIP/2.0/UDP 91.121.78.130;branch=z9hG4bK0bea.0a751ef85c475779e8012ec259ca547a.0;i=7ee Via: SIP/2.0/TCP 192.168.1.110:32866;received=81.82.213.187;rport=32866;branch=z9hG4bKPjHb2FXlTHWuK.SQRI4xsLSRDTdCtt4D2I;alias Max-Forwards: 16 From: sip:david_test@xxxxxxxxxxxxxxx;tag=kiGDpg9qCdBHKMLgabtKNN1RR-6zUtNP To: sip:nana_test at sip.antisip.com;tag=1ZizPkTBq.uBj5BhqiyUu6LNUtq4mkS- Contact: <sip:david_test at 81.82.213.187:55180;alias=81.82.213.187~32866~2;ob>;+sip.ice Call-ID: J8G4AP209IQgmOFQgzCN6.3oBr1724L0 CSeq: 16941 UPDATE Supported: replaces, 100rel, timer, norefersub Session-Expires: 1800;refresher=uac Min-SE: 90 Content-Type: application/sdp Content-Length: 717 v=0 o=- 3634384189 3634384190 IN IP4 81.82.213.187 s=pjmedia b=AS:84 t=0 0 a=X-nat:7 m=audio 4033 RTP/AVP 98 97 99 104 3 0 8 9 96 c=IN IP4 192.168.1.110 b=TIAS:64000 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 a=ice-ufrag:181ccc16 a=ice-pwd:01ad9069 a=rtcp:4024 IN IP4 192.168.1.110 a=candidate:Hc0a8016e 1 UDP 1694498815 192.168.1.110 4033 typ host a=candidate:Hc0a8016e 2 UDP 1694498814 192.168.1.110 4024 typ host a=remote-candidates:1 192.168.1.124 4015 2 192.168.1.124 4001 a=sendrecv --end msg-- 15:09:57.598 dlg0xa1e38c .Received Request msg UPDATE/cseq=16941 (rdata0xa5af4c) 15:09:57.599 tsx0xa8abbc ...Transaction created for Request msg UPDATE/cseq=16941 (rdata0xa5af4c) 15:09:57.599 tsx0xa8abbc ..Incoming Request msg UPDATE/cseq=16941 (rdata0xa5af4c) in state Null 15:09:57.599 tsx0xa8abbc ...State changed from Null to Trying, event=RX_MSG 15:09:57.599 dlg0xa1e38c ....Transaction tsx0xa8abbc state changed to Trying 15:09:57.599 inv0xa1e38c .....Got SDP offer in Request msg UPDATE/cseq=16941 (rdata0xa5af4c) 15:09:57.600 pjsua_call.c .....Call 0: received updated media offer 15:09:57.601 pjsua_media.c ......Call 0: re-initializing media.. 15:09:57.602 pjsua_media.c .......Media index 0 selected for audio call 0 15:09:57.603 icetp00 ......Processing SDP: support ICE=1, common comp_cnt=2, ice_mismatch=0, ice_restart=0, local_role=Controlled 15:09:57.610 inv0xa1e38c .....SDP negotiation done, status=0 15:09:57.610 pjsua_call.c ......Call 0: remote NAT type is 7 (Restricted) 15:09:57.611 pjsua_media.c ......Call 0: updating media.. 15:09:57.612 pjsua_media.c .......Call 0: stream #0 (audio) unchanged. 15:09:57.613 icetp00 .......ICE session unchanged 15:09:57.615 pjsua_media.c .......Audio updated, stream #0: PCMU (sendrecv) 15:09:57.616 pjsua_app.c ......Call 0 media 0 [type=audio], status is Active 15:09:57.629 pjsua_aud.c ......Conf connect: 3 --> 0 15:09:57.639 pjsua_aud.c ......Conf connect: 0 --> 3 15:09:57.640 endpoint .....Response msg 200/UPDATE/cseq=16941 (tdta0xa7cc30) created 15:09:57.641 dlg0xa1e38c ......Sending Response msg 200/UPDATE/cseq=16941 (tdta0xa7cc30) 15:09:57.641 tsx0xa8abbc ......Sending Response msg 200/UPDATE/cseq=16941 (tdta0xa7cc30) in state Trying 15:09:57.641 sip_resolve.c .......Target '91.121.78.130:5060' type=UDP resolved to '91.121.78.130:5060' type=UDP (UDP transport) 15:09:57.642 pjsua_core.c .......TX 1237 bytes Response msg 200/UPDATE/cseq=16941 (tdta0xa7cc30) to UDP 91.121.78.130:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 91.121.78.130;received=91.121.78.130;branch=z9hG4bK0bea.0a751ef85c475779e8012ec259ca547a.0;i=7ee Via: SIP/2.0/TCP 192.168.1.110:32866;rport=32866;received=81.82.213.187;branch=z9hG4bKPjHb2FXlTHWuK.SQRI4xsLSRDTdCtt4D2I;alias Call-ID: J8G4AP209IQgmOFQgzCN6.3oBr1724L0 From: <sip:david_test@xxxxxxxxxxxxxxx>;tag=kiGDpg9qCdBHKMLgabtKNN1RR-6zUtNP To: <sip:nana_test at sip.antisip.com>;tag=1ZizPkTBq.uBj5BhqiyUu6LNUtq4mkS- CSeq: 16941 UPDATE Session-Expires: 1800;refresher=uac Require: timer Contact: <sip:nana_test at 81.82.213.187:5060;ob>;+sip.ice Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS Supported: replaces, 100rel, timer, norefersub Content-Type: application/sdp Content-Length: 452 v=0 o=- 3634384189 3634384191 IN IP4 192.168.1.124 s=pjmedia b=AS:84 t=0 0 a=X-nat:7 m=audio 4015 RTP/AVP 0 96 c=IN IP4 192.168.1.124 b=TIAS:64000 a=sendrecv a=rtpmap:0 PCMU/8000 a=rtpmap:96 telephone-event/8000 a=fmtp:96 0-16 a=ice-ufrag:20b32106 a=ice-pwd:2e0147a9 a=rtcp:4001 IN IP4 192.168.1.124 a=candidate:Hc0a8017c 1 UDP 1694498815 192.168.1.124 4015 typ host a=candidate:Hc0a8017c 2 UDP 1694498814 192.168.1.124 4001 typ host --end msg-- 15:09:57.655 tsx0xa8abbc .......State changed from Trying to Completed, event=TX_MSG 15:09:57.655 dlg0xa1e38c ........Transaction tsx0xa8abbc state changed to Completed 15:09:57.656 tsx0xa1eb94 Timeout timer event 15:09:57.656 tsx0xa1eb94 .State changed from Terminated to Destroyed, event=TIMER 15:09:57.656 tdta0xa64818 ..Destroying txdata Response msg 200/INVITE/cseq=16940 (tdta0xa64818) 15:09:57.656 tsx0xa1eb94 Transaction destroyed! 15:09:57.770 utsx0xa884f0 STUN client transaction 0xa884f0 stopped, ref_cnt=22 15:09:57.771 stun_session.c STUN transaction 0xa884f0 destroyed 15:09:57.777 utsx0xa83ee8 STUN client transaction 0xa83ee8 stopped, ref_cnt=21 15:09:57.777 stun_session.c STUN transaction 0xa83ee8 destroyed 15:09:57.799 utsx0xa86d08 STUN client transaction 0xa86d08 stopped, ref_cnt=20 15:09:57.799 stun_session.c STUN transaction 0xa86d08 destroyed 15:09:57.806 utsx0xa894e0 STUN client transaction 0xa894e0 stopped, ref_cnt=19 15:09:57.806 stun_session.c STUN transaction 0xa894e0 destroyed 15:10:02.258 pjsua_acc.c Sending 2 bytes keep-alive packet for acc 2 to 91.121.78.130:5060 15:10:02.259 tdta0xa64020 Destroying txdata raw 15:10:04.963 stuntp0xa5fa10 .TX 36 bytes STUN message to 208.109.222.137:3478: --- begin STUN message --- STUN Binding request Hdr: length=16, magic=2112a442, tsx_id=4ce461f56b6b0d2b000272b3 Attributes: SOFTWARE: length=12, value="pjnath-2.3.0" --- end of STUN message --- 15:10:04.964 utsx0xa886cc .STUN client transaction created 15:10:04.964 utsx0xa886cc .STUN sending message (transmit count=1) 15:10:04.973 stuntp0xa62318 .TX 36 bytes STUN message to 208.109.222.137:3478: --- begin STUN message --- STUN Binding request Hdr: length=16, magic=2112a442, tsx_id=25e8bd64746286cc00022574 Attributes: SOFTWARE: length=12, value="pjnath-2.3.0" --- end of STUN message --- 15:10:04.973 utsx0xa840c4 .STUN client transaction created 15:10:04.973 utsx0xa840c4 .STUN sending message (transmit count=1) 15:10:05.064 utsx0xa886cc STUN sending message (transmit count=2) 15:10:05.074 utsx0xa840c4 STUN sending message (transmit count=2) 15:10:05.107 stun_msg.c .Unrecognized attribute type 0x8020 15:10:05.108 stuntp0xa5fa10 .RX 88 bytes STUN message from 208.109.222.137:3478: --- begin STUN message --- STUN Binding success response Hdr: length=68, magic=2112a442, tsx_id=4ce461f56b6b0d2b000272b3 Attributes: MAPPED-ADDRESS: length=8, IPv4 addr=81.82.213.187:4015 SOURCE-ADDRESS: length=8, IPv4 addr=208.109.222.137:3479 CHANGED-ADDRESS: length=8, IPv4 addr=208.109.222.148:3478 Attr 0x8020: length=8 SOFTWARE: length=16, value="Vovida.org 0.96" --- end of STUN message --- 15:10:05.108 stun_session.c .tdata 0xa1fbb4 destroy request, force=0, tsx=0xa886cc 15:10:05.108 utsx0xa886cc .STUN transaction 0xa886cc schedule destroy 15:10:05.120 stun_msg.c .Unrecognized attribute type 0x8020 15:10:05.121 stuntp0xa62318 .RX 88 bytes STUN message from 208.109.222.137:3478: --- begin STUN message --- STUN Binding success response Hdr: length=68, magic=2112a442, tsx_id=25e8bd64746286cc00022574 Attributes: MAPPED-ADDRESS: length=8, IPv4 addr=81.82.213.187:4001 SOURCE-ADDRESS: length=8, IPv4 addr=208.109.222.137:3479 CHANGED-ADDRESS: length=8, IPv4 addr=208.109.222.148:3478 Attr 0x8020: length=8 SOFTWARE: length=16, value="Vovida.org 0.96" --- end of STUN message --- 15:10:05.121 stun_session.c .tdata 0xa887d4 destroy request, force=0, tsx=0xa840c4 15:10:05.121 utsx0xa840c4 .STUN transaction 0xa840c4 schedule destroy 15:10:05.208 stun_msg.c .Unrecognized attribute type 0x8020 15:10:05.208 stuntp0xa5fa10 .RX 88 bytes STUN message from 208.109.222.137:3478: --- begin STUN message --- STUN Binding success response Hdr: length=68, magic=2112a442, tsx_id=4ce461f56b6b0d2b000272b3 Attributes: MAPPED-ADDRESS: length=8, IPv4 addr=81.82.213.187:4015 SOURCE-ADDRESS: length=8, IPv4 addr=208.109.222.137:3479 CHANGED-ADDRESS: length=8, IPv4 addr=208.109.222.148:3478 Attr 0x8020: length=8 SOFTWARE: length=16, value="Vovida.org 0.96" --- end of STUN message --- 15:10:05.225 stun_msg.c .Unrecognized attribute type 0x8020 15:10:05.226 stuntp0xa62318 .RX 88 bytes STUN message from 208.109.222.137:3478: --- begin STUN message --- STUN Binding success response Hdr: length=68, magic=2112a442, tsx_id=25e8bd64746286cc00022574 Attributes: MAPPED-ADDRESS: length=8, IPv4 addr=81.82.213.187:4001 SOURCE-ADDRESS: length=8, IPv4 addr=208.109.222.137:3479 CHANGED-ADDRESS: length=8, IPv4 addr=208.109.222.148:3478 Attr 0x8020: length=8 SOFTWARE: length=16, value="Vovida.org 0.96" --- end of STUN message --- 15:10:05.408 utsx0xa886cc STUN client transaction 0xa886cc stopped, ref_cnt=20 15:10:05.408 stun_session.c STUN transaction 0xa886cc destroyed 15:10:05.422 utsx0xa840c4 STUN client transaction 0xa840c4 stopped, ref_cnt=19 15:10:05.422 stun_session.c STUN transaction 0xa840c4 destroyed 15:10:06.492 pjsua_app_comm ! [CONFIRMED] To: <sip:david_test at sip.antisip.com>;tag=kiGDpg9qCdBHKMLgabtKNN1RR-6zUtNP Call time: 00h:00m:08s, 1st res in 7505 ms, conn in 7779ms #0 audio PCMU @8kHz, sendrecv, peer=91.121.78.130:51526 SRTP status: Not active Crypto-suite: ICE role: Controlled, state: Negotiation Success, comp_cnt: 2 [0]: L:192.168.1.124:4015 (h) --> R:192.168.1.110:4033 (h) [1]: L:192.168.1.124:4001 (h) --> R:192.168.1.110:4024 (h) RX pt=0, last update:00h:00m:08.808s ago total 449pkt 71.8KB (89.8KB +IP hdr) @avg=62.8Kbps/78.5Kbps pkt loss=0 (0.0%), discrd=0 (0.0%), dup=0 (0.0%), reord=0 (0.0%) (msec) min avg max last dev loss period: 0.000 0.000 0.000 0.000 0.000 jitter : 0.000 2.247 9.250 0.750 1.971 TX pt=0, ptime=20, last update:00h:00m:04.429s ago total 8pkt 1.2KB (1.6KB +IP hdr) @avg=1.1Kbps/1.3Kbps pkt loss=0 (0.0%), dup=0 (0.0%), reorder=0 (0.0%) (msec) min avg max last dev loss period: 0.000 0.000 0.000 0.000 0.000 jitter : 0.000 0.000 0.000 0.000 0.000 RTT msec : 4.425 4.425 4.425 4.425 0.000 15:10:07.422 stuse0xa7a240 !Response cache deleted 15:10:07.422 stun_session.c tdata 0xa873f4 destroy request, force=0, tsx=(nil) 15:10:07.434 stuse0xa7b228 Response cache deleted 15:10:07.434 stun_session.c tdata 0xa87bec destroy request, force=0, tsx=(nil) 15:10:07.473 stuse0xa7a240 Response cache deleted 15:10:07.473 stun_session.c tdata 0xa88bdc destroy request, force=0, tsx=(nil) 15:10:07.488 stuse0xa7b228 Response cache deleted 15:10:07.489 stun_session.c tdata 0xa89bcc destroy request, force=0, tsx=(nil) 15:10:07.508 stuse0xa7b228 Response cache deleted 15:10:07.508 stun_session.c tdata 0xa8a3c4 destroy request, force=0, tsx=(nil) 15:10:07.991 stuse0xa7a240 .RX 20 bytes STUN message from 192.168.1.110:4033: --- begin STUN message --- STUN Binding indication Hdr: length=0, magic=2112a442, tsx_id=00005f285ea8051d4b509967 Attributes: --- end of STUN message --- 15:10:07.992 icetp00 ..Received Binding Indication keep-alive for component 1 15:10:08.014 stuse0xa7a240 .TX 20 bytes STUN message to 192.168.1.110:4033: --- begin STUN message --- STUN Binding indication Hdr: length=0, magic=2112a442, tsx_id=00000955316d55890e7c55d3 Attributes: --- end of STUN message --- 15:10:08.014 stun_session.c .tdata 0xa1fbb4 destroy request, force=0, tsx=(nil) 15:10:17.260 pjsua_acc.c Sending 2 bytes keep-alive packet for acc 2 to 91.121.78.130:5060 15:10:17.261 tdta0xa64020 Destroying txdata raw 15:10:17.929 sip_endpoint.c Processing incoming message: Request msg BYE/cseq=16942 (rdata0xa5af4c) 15:10:17.929 pjsua_core.c .RX 574 bytes Request msg BYE/cseq=16942 (rdata0xa5af4c) from UDP 91.121.78.130:5060: BYE sip:nana_test at 81.82.213.187:5060;ob SIP/2.0 Via: SIP/2.0/UDP 91.121.78.130;branch=z9hG4bKdaea.84a8b3293c04907e5dfb8e94231f51b1.0;i=7ee Via: SIP/2.0/TCP 192.168.1.110:32866;received=81.82.213.187;rport=32866;branch=z9hG4bKPjxeuSVOrWqxA7Gs75wIJe2PY2uzyLcJ3Q;alias Max-Forwards: 16 From: sip:david_test@xxxxxxxxxxxxxxx;tag=kiGDpg9qCdBHKMLgabtKNN1RR-6zUtNP To: sip:nana_test at sip.antisip.com;tag=1ZizPkTBq.uBj5BhqiyUu6LNUtq4mkS- Call-ID: J8G4AP209IQgmOFQgzCN6.3oBr1724L0 CSeq: 16942 BYE User-Agent: PJSUA v2.3 Linux-3.13.0.46/x86_64/glibc-2.19 Content-Length: 0 --end msg-- 15:10:17.930 dlg0xa1e38c .Received Request msg BYE/cseq=16942 (rdata0xa5af4c) 15:10:17.931 tsx0xa1eb94 ...Transaction created for Request msg BYE/cseq=16942 (rdata0xa5af4c) 15:10:17.931 tsx0xa1eb94 ..Incoming Request msg BYE/cseq=16942 (rdata0xa5af4c) in state Null 15:10:17.931 tsx0xa1eb94 ...State changed from Null to Trying, event=RX_MSG 15:10:17.932 dlg0xa1e38c ....Transaction tsx0xa1eb94 state changed to Trying 15:10:17.932 endpoint .....Response msg 200/BYE/cseq=16942 (tdta0xa64020) created 15:10:17.932 dlg0xa1e38c ......Sending Response msg 200/BYE/cseq=16942 (tdta0xa64020) 15:10:17.932 tsx0xa1eb94 ......Sending Response msg 200/BYE/cseq=16942 (tdta0xa64020) in state Trying 15:10:17.932 sip_resolve.c .......Target '91.121.78.130:5060' type=UDP resolved to '91.121.78.130:5060' type=UDP (UDP transport) 15:10:17.933 pjsua_core.c .......TX 492 bytes Response msg 200/BYE/cseq=16942 (tdta0xa64020) to UDP 91.121.78.130:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 91.121.78.130;received=91.121.78.130;branch=z9hG4bKdaea.84a8b3293c04907e5dfb8e94231f51b1.0;i=7ee Via: SIP/2.0/TCP 192.168.1.110:32866;rport=32866;received=81.82.213.187;branch=z9hG4bKPjxeuSVOrWqxA7Gs75wIJe2PY2uzyLcJ3Q;alias Call-ID: J8G4AP209IQgmOFQgzCN6.3oBr1724L0 From: <sip:david_test@xxxxxxxxxxxxxxx>;tag=kiGDpg9qCdBHKMLgabtKNN1RR-6zUtNP To: <sip:nana_test at sip.antisip.com>;tag=1ZizPkTBq.uBj5BhqiyUu6LNUtq4mkS- CSeq: 16942 BYE Content-Length: 0 --end msg-- 15:10:17.934 tsx0xa1eb94 .......State changed from Trying to Completed, event=TX_MSG 15:10:17.935 dlg0xa1e38c ........Transaction tsx0xa1eb94 state changed to Completed 15:10:17.935 pjsua_app.c ......Call 0 is DISCONNECTED [reason=200 (Normal call clearing)] 15:10:17.936 pjsua_app.c ......Call 0
