STUN Binding request times out after 200 OK received on client
Hi, I am developing an iOS calling App with libnice for ICE capabilities. The calls go through freeswitch and since freeswitch supports ICE, I expected it to work out of the box. But I have a problem. The way libnice works is as follows: 1) The client sends INVITE with his candidates. 2) Freeswitch parses the candidates. 3) Immediately after 200 OK is received, I can see FreeSWITCH choosing an ICE candidate and logging "Activating Audio ICE" indicating the IP and Port and it sends media/RTP to. 4) But the libnice agent tries to look at the candidates received in 200 OK and tries to send a STUN binding request to FreeSWITCH IP as that IP is mentioned as ICE candidate in the 200 OK coming from freeswitch. 5) The FreeSWITCH doesn't respond to that STUN binding request and libnice agent times out. 6) Ideally, if libnice gets back a response from the freeswitch, it should initiate a Re-INVITE with the candidate pair selected. Now here, the freeswitch starts sending RTP to client's candidate, but the client gets stuck because the candidate pair is not formed as the libnice agent keeps waiting for a response for the STUN Binding Request. Is there anything that I am missing here. Any help is highly appreciated. Thanks, --- Jayesh
Its possible that we have some conditions wrong for non-webrtc ice. You are going to need to trace the switch_core_media code a bit and see how we parse the sdp, what we are expecting, and how we turn on ice. I suspect we have conditions that tie some of the ice functionality incorrectly to other things required for webrtc. On Jun 10, 2014, at 2:09 PM, Jayesh Nambiar <jayesh1017@gmail.com> wrote:
Hi, I am developing an iOS calling App with libnice for ICE capabilities. The calls go through freeswitch and since freeswitch supports ICE, I expected it to work out of the box. But I have a problem. The way libnice works is as follows: 1) The client sends INVITE with his candidates. 2) Freeswitch parses the candidates. 3) Immediately after 200 OK is received, I can see FreeSWITCH choosing an ICE candidate and logging "Activating Audio ICE" indicating the IP and Port and it sends media/RTP to. 4) But the libnice agent tries to look at the candidates received in 200 OK and tries to send a STUN binding request to FreeSWITCH IP as that IP is mentioned as ICE candidate in the 200 OK coming from freeswitch. 5) The FreeSWITCH doesn't respond to that STUN binding request and libnice agent times out. 6) Ideally, if libnice gets back a response from the freeswitch, it should initiate a Re-INVITE with the candidate pair selected.
Now here, the freeswitch starts sending RTP to client's candidate, but the client gets stuck because the candidate pair is not formed as the libnice agent keeps waiting for a response for the STUN Binding Request. Is there anything that I am missing here. Any help is highly appreciated.
I think Michael's insight appears to be correct. I say this because I also can't seem to get ICE to work correctly with FS when using the CSipSimple client with ICE support. As you can see in the CSipSimple logs here, it seems that FS fails to correctly respond to the STUN binding request, and thus ICE negotiation fails: 17:17:58.927 icetp00 ..Triggered check for check 1 not performed because it's in progress. Retransmitting 17:17:58.927 utsx0x5dee930c ...STUN sending message (transmit count=7) 17:17:59.040 timer_android. !FIRE timer 26 of heap 16 17:17:59.040 utsx0x5f6e659c STUN timeout waiting for response 17:17:59.040 icetp00 .Check 2: [2] 192.168.1.4:4037-->79.my.serverIP:62203 (nominated): connectivity check FAILED: STUN transaction has timed out (PJNATH_ESTUNTIMEDOUT) 17:17:59.040 icetp00 ..Check 2: [2] 192.168.1.4:4037-->79.my.serverIP:62203: state changed from In Progress to Failed 17:17:59.040 stun_session.c .tdata 0x5f6e6484 destroy request, force=1, tsx=0x5f6e659c 17:17:59.040 timer_android. .Ask to cancel something already fired or cancelled : -1 @ 0x5f6e65dc 17:17:59.040 utsx0x5f6e659c .STUN client transaction 0x5f6e659c stopped, ref_cnt=46 17:17:59.041 timer_android. FIRE done and released 17:17:59.238 timer_android. FIRE timer 27 of heap 16 17:17:59.238 utsx0x5d9a080c STUN timeout waiting for response 17:17:59.238 icetp00 .Check 0: [1] 192.168.1.4:4001-->79.my.serverIP:62202 (nominated): connectivity check FAILED: STUN transaction has timed out (PJNATH_ESTUNTIMEDOUT) 17:17:59.239 icetp00 ..Check 0: [1] 192.168.1.4:4001-->79.my.serverIP:62202: state changed from In Progress to Failed 17:17:59.239 stun_session.c .tdata 0x5d9a06f4 destroy request, force=1, tsx=0x5d9a080c 17:17:59.239 timer_android. .Ask to cancel something already fired or cancelled : -1 @ 0x5d9a084c 17:17:59.239 utsx0x5d9a080c .STUN client transaction 0x5d9a080c stopped, ref_cnt=45 17:17:59.239 timer_android. FIRE done and released 17:17:59.257 timer_android. FIRE timer 28 of heap 16 17:17:59.257 utsx0x5dee930c STUN timeout waiting for response 17:17:59.257 icetp00 .Check 1: [1] 79.my.serverIP:56378-->79.my.serverIP:62202 (nominated): connectivity check FAILED: STUN transaction has timed out (PJNATH_ESTUNTIMEDOUT) 17:17:59.257 icetp00 ..Check 1: [1] 79.my.serverIP:56378-->79.my.serverIP:62202: state changed from In Progress to Failed 17:17:59.258 stun_session.c .tdata 0x5dee91f4 destroy request, force=1, tsx=0x5dee930c 17:17:59.258 timer_android. .Ask to cancel something already fired or cancelled : -1 @ 0x5dee934c 17:17:59.258 utsx0x5dee930c .STUN client transaction 0x5dee930c stopped, ref_cnt=44 17:17:59.258 timer_android. FIRE done and released 17:17:59.273 timer_android. FIRE timer 34 of heap 16 17:17:59.274 utsx0x5da8db64 STUN timeout waiting for response 17:17:59.274 icetp00 .Check 3: [2] 79.my.serverIP2:54506-->79.my.serverIP:62203 (nominated): connectivity check FAILED: STUN transaction has timed out (PJNATH_ESTUNTIMEDOUT) 17:17:59.274 icetp00 ..Check 3: [2] 79.my.serverIP2:54506-->79.my.serverIP:62203: state changed from In Progress to Failed 17:17:59.274 timer_android. ..Ask to cancel something already fired or cancelled : -1 @ 0x5dc0b400 17:17:59.274 icetp00 ..ICE process complete, status=All ICE checklists failed (PJNATH_EICEFAILED) 17:17:59.274 icetp00 ..Valid list 17:17:59.274 timer_android. ..Scheduling timer 30 of 16 in 0 ms @ 0x5dc0b400 17:17:59.278 stun_session.c .tdata 0x5da8da4c destroy request, force=1, tsx=0x5da8db64 17:17:59.278 timer_android. .Ask to cancel something already fired or cancelled : -1 @ 0x5da8dba4 17:17:59.278 utsx0x5da8db64 .STUN client transaction 0x5da8db64 stopped, ref_cnt=45 17:17:59.278 timer_android. FIRE done and released 17:17:59.289 timer_android. FIRE timer 30 of heap 16 17:17:59.289 icetp00 ICE negotiation failed after 8s:424: All ICE checklists failed (PJNATH_EICEFAILED) On Tue, Jun 10, 2014 at 3:27 PM, Michael Jerris <mike@jerris.com> wrote:
Its possible that we have some conditions wrong for non-webrtc ice. You are going to need to trace the switch_core_media code a bit and see how we parse the sdp, what we are expecting, and how we turn on ice. I suspect we have conditions that tie some of the ice functionality incorrectly to other things required for webrtc.
On Jun 10, 2014, at 2:09 PM, Jayesh Nambiar <jayesh1017@gmail.com> wrote:
Hi, I am developing an iOS calling App with libnice for ICE capabilities. The calls go through freeswitch and since freeswitch supports ICE, I expected it to work out of the box. But I have a problem. The way libnice works is as follows: 1) The client sends INVITE with his candidates. 2) Freeswitch parses the candidates. 3) Immediately after 200 OK is received, I can see FreeSWITCH choosing an ICE candidate and logging "Activating Audio ICE" indicating the IP and Port and it sends media/RTP to. 4) But the libnice agent tries to look at the candidates received in 200 OK and tries to send a STUN binding request to FreeSWITCH IP as that IP is mentioned as ICE candidate in the 200 OK coming from freeswitch. 5) The FreeSWITCH doesn't respond to that STUN binding request and libnice agent times out. 6) Ideally, if libnice gets back a response from the freeswitch, it should initiate a Re-INVITE with the candidate pair selected.
Now here, the freeswitch starts sending RTP to client's candidate, but the client gets stuck because the candidate pair is not formed as the libnice agent keeps waiting for a response for the STUN Binding Request. Is there anything that I am missing here. Any help is highly appreciated.
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com
FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com
Official FreeSWITCH Sites http://www.freeswitch.org http://wiki.freeswitch.org http://www.cluecon.com
FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
Indeed there seems to be a bug in ICE. This stun timeout was leading to problems in delaying ZRTP negotiation as I reported here http://lists.freeswitch.org/pipermail/freeswitch-users/2014-June/105892.html Once I turn off ICE in the client, the problem's resolved. So it appears that FS's ICE implementation is not working as it should for non WebRTC scenarios. On Tue, Jun 10, 2014 at 6:43 PM, Peter Villeneuve <petervnv1@gmail.com> wrote:
I think Michael's insight appears to be correct. I say this because I also can't seem to get ICE to work correctly with FS when using the CSipSimple client with ICE support.
As you can see in the CSipSimple logs here, it seems that FS fails to correctly respond to the STUN binding request, and thus ICE negotiation fails:
17:17:58.927 icetp00 ..Triggered check for check 1 not performed because it's in progress. Retransmitting 17:17:58.927 utsx0x5dee930c ...STUN sending message (transmit count=7) 17:17:59.040 timer_android. !FIRE timer 26 of heap 16 17:17:59.040 utsx0x5f6e659c STUN timeout waiting for response 17:17:59.040 icetp00 .Check 2: [2] 192.168.1.4:4037-->79.my.serverIP:62203 (nominated): connectivity check FAILED: STUN transaction has timed out (PJNATH_ESTUNTIMEDOUT) 17:17:59.040 icetp00 ..Check 2: [2] 192.168.1.4:4037-->79.my.serverIP:62203: state changed from In Progress to Failed 17:17:59.040 stun_session.c .tdata 0x5f6e6484 destroy request, force=1, tsx=0x5f6e659c 17:17:59.040 timer_android. .Ask to cancel something already fired or cancelled : -1 @ 0x5f6e65dc 17:17:59.040 utsx0x5f6e659c .STUN client transaction 0x5f6e659c stopped, ref_cnt=46 17:17:59.041 timer_android. FIRE done and released 17:17:59.238 timer_android. FIRE timer 27 of heap 16 17:17:59.238 utsx0x5d9a080c STUN timeout waiting for response 17:17:59.238 icetp00 .Check 0: [1] 192.168.1.4:4001-->79.my.serverIP:62202 (nominated): connectivity check FAILED: STUN transaction has timed out (PJNATH_ESTUNTIMEDOUT) 17:17:59.239 icetp00 ..Check 0: [1] 192.168.1.4:4001-->79.my.serverIP:62202: state changed from In Progress to Failed 17:17:59.239 stun_session.c .tdata 0x5d9a06f4 destroy request, force=1, tsx=0x5d9a080c 17:17:59.239 timer_android. .Ask to cancel something already fired or cancelled : -1 @ 0x5d9a084c 17:17:59.239 utsx0x5d9a080c .STUN client transaction 0x5d9a080c stopped, ref_cnt=45 17:17:59.239 timer_android. FIRE done and released 17:17:59.257 timer_android. FIRE timer 28 of heap 16 17:17:59.257 utsx0x5dee930c STUN timeout waiting for response 17:17:59.257 icetp00 .Check 1: [1] 79.my.serverIP:56378-->79.my.serverIP:62202 (nominated): connectivity check FAILED: STUN transaction has timed out (PJNATH_ESTUNTIMEDOUT) 17:17:59.257 icetp00 ..Check 1: [1] 79.my.serverIP:56378-->79.my.serverIP:62202: state changed from In Progress to Failed 17:17:59.258 stun_session.c .tdata 0x5dee91f4 destroy request, force=1, tsx=0x5dee930c 17:17:59.258 timer_android. .Ask to cancel something already fired or cancelled : -1 @ 0x5dee934c 17:17:59.258 utsx0x5dee930c .STUN client transaction 0x5dee930c stopped, ref_cnt=44 17:17:59.258 timer_android. FIRE done and released 17:17:59.273 timer_android. FIRE timer 34 of heap 16 17:17:59.274 utsx0x5da8db64 STUN timeout waiting for response 17:17:59.274 icetp00 .Check 3: [2] 79.my.serverIP2:54506-->79.my.serverIP:62203 (nominated): connectivity check FAILED: STUN transaction has timed out (PJNATH_ESTUNTIMEDOUT) 17:17:59.274 icetp00 ..Check 3: [2] 79.my.serverIP2:54506-->79.my.serverIP:62203: state changed from In Progress to Failed 17:17:59.274 timer_android. ..Ask to cancel something already fired or cancelled : -1 @ 0x5dc0b400 17:17:59.274 icetp00 ..ICE process complete, status=All ICE checklists failed (PJNATH_EICEFAILED) 17:17:59.274 icetp00 ..Valid list 17:17:59.274 timer_android. ..Scheduling timer 30 of 16 in 0 ms @ 0x5dc0b400 17:17:59.278 stun_session.c .tdata 0x5da8da4c destroy request, force=1, tsx=0x5da8db64 17:17:59.278 timer_android. .Ask to cancel something already fired or cancelled : -1 @ 0x5da8dba4 17:17:59.278 utsx0x5da8db64 .STUN client transaction 0x5da8db64 stopped, ref_cnt=45 17:17:59.278 timer_android. FIRE done and released 17:17:59.289 timer_android. FIRE timer 30 of heap 16 17:17:59.289 icetp00 ICE negotiation failed after 8s:424: All ICE checklists failed (PJNATH_EICEFAILED)
On Tue, Jun 10, 2014 at 3:27 PM, Michael Jerris <mike@jerris.com> wrote:
Its possible that we have some conditions wrong for non-webrtc ice. You are going to need to trace the switch_core_media code a bit and see how we parse the sdp, what we are expecting, and how we turn on ice. I suspect we have conditions that tie some of the ice functionality incorrectly to other things required for webrtc.
On Jun 10, 2014, at 2:09 PM, Jayesh Nambiar <jayesh1017@gmail.com> wrote:
Hi, I am developing an iOS calling App with libnice for ICE capabilities. The calls go through freeswitch and since freeswitch supports ICE, I expected it to work out of the box. But I have a problem. The way libnice works is as follows: 1) The client sends INVITE with his candidates. 2) Freeswitch parses the candidates. 3) Immediately after 200 OK is received, I can see FreeSWITCH choosing an ICE candidate and logging "Activating Audio ICE" indicating the IP and Port and it sends media/RTP to. 4) But the libnice agent tries to look at the candidates received in 200 OK and tries to send a STUN binding request to FreeSWITCH IP as that IP is mentioned as ICE candidate in the 200 OK coming from freeswitch. 5) The FreeSWITCH doesn't respond to that STUN binding request and libnice agent times out. 6) Ideally, if libnice gets back a response from the freeswitch, it should initiate a Re-INVITE with the candidate pair selected.
Now here, the freeswitch starts sending RTP to client's candidate, but the client gets stuck because the candidate pair is not formed as the libnice agent keeps waiting for a response for the STUN Binding Request. Is there anything that I am missing here. Any help is highly appreciated.
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com
FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com
Official FreeSWITCH Sites http://www.freeswitch.org http://wiki.freeswitch.org http://www.cluecon.com
FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
Tony just tested this and it worked with csipsimple. Can you confirm if you are testing with freeswitch from latest git master? is the server side on a public ip or behind nat? Mike On Jun 10, 2014, at 5:43 PM, Peter Villeneuve <petervnv1@gmail.com> wrote:
I think Michael's insight appears to be correct. I say this because I also can't seem to get ICE to work correctly with FS when using the CSipSimple client with ICE support.
As you can see in the CSipSimple logs here, it seems that FS fails to correctly respond to the STUN binding request, and thus ICE negotiation fails:
17:17:58.927 icetp00 ..Triggered check for check 1 not performed because it's in progress. Retransmitting 17:17:58.927 utsx0x5dee930c ...STUN sending message (transmit count=7) 17:17:59.040 timer_android. !FIRE timer 26 of heap 16 17:17:59.040 utsx0x5f6e659c STUN timeout waiting for response 17:17:59.040 icetp00 .Check 2: [2] 192.168.1.4:4037-->79.my.serverIP:62203 (nominated): connectivity check FAILED: STUN transaction has timed out (PJNATH_ESTUNTIMEDOUT) 17:17:59.040 icetp00 ..Check 2: [2] 192.168.1.4:4037-->79.my.serverIP:62203: state changed from In Progress to Failed 17:17:59.040 stun_session.c .tdata 0x5f6e6484 destroy request, force=1, tsx=0x5f6e659c 17:17:59.040 timer_android. .Ask to cancel something already fired or cancelled : -1 @ 0x5f6e65dc 17:17:59.040 utsx0x5f6e659c .STUN client transaction 0x5f6e659c stopped, ref_cnt=46 17:17:59.041 timer_android. FIRE done and released 17:17:59.238 timer_android. FIRE timer 27 of heap 16 17:17:59.238 utsx0x5d9a080c STUN timeout waiting for response 17:17:59.238 icetp00 .Check 0: [1] 192.168.1.4:4001-->79.my.serverIP:62202 (nominated): connectivity check FAILED: STUN transaction has timed out (PJNATH_ESTUNTIMEDOUT) 17:17:59.239 icetp00 ..Check 0: [1] 192.168.1.4:4001-->79.my.serverIP:62202: state changed from In Progress to Failed 17:17:59.239 stun_session.c .tdata 0x5d9a06f4 destroy request, force=1, tsx=0x5d9a080c 17:17:59.239 timer_android. .Ask to cancel something already fired or cancelled : -1 @ 0x5d9a084c 17:17:59.239 utsx0x5d9a080c .STUN client transaction 0x5d9a080c stopped, ref_cnt=45 17:17:59.239 timer_android. FIRE done and released 17:17:59.257 timer_android. FIRE timer 28 of heap 16 17:17:59.257 utsx0x5dee930c STUN timeout waiting for response 17:17:59.257 icetp00 .Check 1: [1] 79.my.serverIP:56378-->79.my.serverIP:62202 (nominated): connectivity check FAILED: STUN transaction has timed out (PJNATH_ESTUNTIMEDOUT) 17:17:59.257 icetp00 ..Check 1: [1] 79.my.serverIP:56378-->79.my.serverIP:62202: state changed from In Progress to Failed 17:17:59.258 stun_session.c .tdata 0x5dee91f4 destroy request, force=1, tsx=0x5dee930c 17:17:59.258 timer_android. .Ask to cancel something already fired or cancelled : -1 @ 0x5dee934c 17:17:59.258 utsx0x5dee930c .STUN client transaction 0x5dee930c stopped, ref_cnt=44 17:17:59.258 timer_android. FIRE done and released 17:17:59.273 timer_android. FIRE timer 34 of heap 16 17:17:59.274 utsx0x5da8db64 STUN timeout waiting for response 17:17:59.274 icetp00 .Check 3: [2] 79.my.serverIP2:54506-->79.my.serverIP:62203 (nominated): connectivity check FAILED: STUN transaction has timed out (PJNATH_ESTUNTIMEDOUT) 17:17:59.274 icetp00 ..Check 3: [2] 79.my.serverIP2:54506-->79.my.serverIP:62203: state changed from In Progress to Failed 17:17:59.274 timer_android. ..Ask to cancel something already fired or cancelled : -1 @ 0x5dc0b400 17:17:59.274 icetp00 ..ICE process complete, status=All ICE checklists failed (PJNATH_EICEFAILED) 17:17:59.274 icetp00 ..Valid list 17:17:59.274 timer_android. ..Scheduling timer 30 of 16 in 0 ms @ 0x5dc0b400 17:17:59.278 stun_session.c .tdata 0x5da8da4c destroy request, force=1, tsx=0x5da8db64 17:17:59.278 timer_android. .Ask to cancel something already fired or cancelled : -1 @ 0x5da8dba4 17:17:59.278 utsx0x5da8db64 .STUN client transaction 0x5da8db64 stopped, ref_cnt=45 17:17:59.278 timer_android. FIRE done and released 17:17:59.289 timer_android. FIRE timer 30 of heap 16 17:17:59.289 icetp00 ICE negotiation failed after 8s:424: All ICE checklists failed (PJNATH_EICEFAILED)
On Tue, Jun 10, 2014 at 3:27 PM, Michael Jerris <mike@jerris.com> wrote: Its possible that we have some conditions wrong for non-webrtc ice. You are going to need to trace the switch_core_media code a bit and see how we parse the sdp, what we are expecting, and how we turn on ice. I suspect we have conditions that tie some of the ice functionality incorrectly to other things required for webrtc.
On Jun 10, 2014, at 2:09 PM, Jayesh Nambiar <jayesh1017@gmail.com> wrote:
Hi, I am developing an iOS calling App with libnice for ICE capabilities. The calls go through freeswitch and since freeswitch supports ICE, I expected it to work out of the box. But I have a problem. The way libnice works is as follows: 1) The client sends INVITE with his candidates. 2) Freeswitch parses the candidates. 3) Immediately after 200 OK is received, I can see FreeSWITCH choosing an ICE candidate and logging "Activating Audio ICE" indicating the IP and Port and it sends media/RTP to. 4) But the libnice agent tries to look at the candidates received in 200 OK and tries to send a STUN binding request to FreeSWITCH IP as that IP is mentioned as ICE candidate in the 200 OK coming from freeswitch. 5) The FreeSWITCH doesn't respond to that STUN binding request and libnice agent times out. 6) Ideally, if libnice gets back a response from the freeswitch, it should initiate a Re-INVITE with the candidate pair selected.
Now here, the freeswitch starts sending RTP to client's candidate, but the client gets stuck because the candidate pair is not formed as the libnice agent keeps waiting for a response for the STUN Binding Request. Is there anything that I am missing here. Any help is highly appreciated.
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com
FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com
Official FreeSWITCH Sites http://www.freeswitch.org http://wiki.freeswitch.org http://www.cluecon.com
FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com
FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com
Official FreeSWITCH Sites http://www.freeswitch.org http://wiki.freeswitch.org http://www.cluecon.com
FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
I'm using FreeSWITCH Version 1.5.13b+git~20140515T183425Z~ebc0a99f1c~64bit. Server is on a public IP. What version of CSipSimple did Tony use to test? There have been some changes recently to ICE in CSip. I'm using latest nightly release (2414) http://nightlies.csipsimple.com/trunk/ with ICE set to aggressive mode. Also, I have Kamailio in front of FS on the same server, but that shouldn't really be an issue, no? Anyway, I have some FS logs posted here if you want to take a closer look http://pastebin.com/WNGcpTqB But I did just confirm that all works as expected with ICE turned off in CSip. On Tue, Jun 10, 2014 at 9:13 PM, Michael Jerris <mike@jerris.com> wrote:
Tony just tested this and it worked with csipsimple. Can you confirm if you are testing with freeswitch from latest git master? is the server side on a public ip or behind nat?
Mike
On Jun 10, 2014, at 5:43 PM, Peter Villeneuve <petervnv1@gmail.com> wrote:
I think Michael's insight appears to be correct. I say this because I also can't seem to get ICE to work correctly with FS when using the CSipSimple client with ICE support.
As you can see in the CSipSimple logs here, it seems that FS fails to correctly respond to the STUN binding request, and thus ICE negotiation fails:
17:17:58.927 icetp00 ..Triggered check for check 1 not performed because it's in progress. Retransmitting 17:17:58.927 utsx0x5dee930c ...STUN sending message (transmit count=7) 17:17:59.040 timer_android. !FIRE timer 26 of heap 16 17:17:59.040 utsx0x5f6e659c STUN timeout waiting for response 17:17:59.040 icetp00 .Check 2: [2] 192.168.1.4:4037-->79.my.serverIP:62203 (nominated): connectivity check FAILED: STUN transaction has timed out (PJNATH_ESTUNTIMEDOUT) 17:17:59.040 icetp00 ..Check 2: [2] 192.168.1.4:4037-->79.my.serverIP:62203: state changed from In Progress to Failed 17:17:59.040 stun_session.c .tdata 0x5f6e6484 destroy request, force=1, tsx=0x5f6e659c 17:17:59.040 timer_android. .Ask to cancel something already fired or cancelled : -1 @ 0x5f6e65dc 17:17:59.040 utsx0x5f6e659c .STUN client transaction 0x5f6e659c stopped, ref_cnt=46 17:17:59.041 timer_android. FIRE done and released 17:17:59.238 timer_android. FIRE timer 27 of heap 16 17:17:59.238 utsx0x5d9a080c STUN timeout waiting for response 17:17:59.238 icetp00 .Check 0: [1] 192.168.1.4:4001-->79.my.serverIP:62202 (nominated): connectivity check FAILED: STUN transaction has timed out (PJNATH_ESTUNTIMEDOUT) 17:17:59.239 icetp00 ..Check 0: [1] 192.168.1.4:4001-->79.my.serverIP:62202: state changed from In Progress to Failed 17:17:59.239 stun_session.c .tdata 0x5d9a06f4 destroy request, force=1, tsx=0x5d9a080c 17:17:59.239 timer_android. .Ask to cancel something already fired or cancelled : -1 @ 0x5d9a084c 17:17:59.239 utsx0x5d9a080c .STUN client transaction 0x5d9a080c stopped, ref_cnt=45 17:17:59.239 timer_android. FIRE done and released 17:17:59.257 timer_android. FIRE timer 28 of heap 16 17:17:59.257 utsx0x5dee930c STUN timeout waiting for response 17:17:59.257 icetp00 .Check 1: [1] 79.my.serverIP:56378-->79.my.serverIP:62202 (nominated): connectivity check FAILED: STUN transaction has timed out (PJNATH_ESTUNTIMEDOUT) 17:17:59.257 icetp00 ..Check 1: [1] 79.my.serverIP:56378-->79.my.serverIP:62202: state changed from In Progress to Failed 17:17:59.258 stun_session.c .tdata 0x5dee91f4 destroy request, force=1, tsx=0x5dee930c 17:17:59.258 timer_android. .Ask to cancel something already fired or cancelled : -1 @ 0x5dee934c 17:17:59.258 utsx0x5dee930c .STUN client transaction 0x5dee930c stopped, ref_cnt=44 17:17:59.258 timer_android. FIRE done and released 17:17:59.273 timer_android. FIRE timer 34 of heap 16 17:17:59.274 utsx0x5da8db64 STUN timeout waiting for response 17:17:59.274 icetp00 .Check 3: [2] 79.my.serverIP2:54506-->79.my.serverIP:62203 (nominated): connectivity check FAILED: STUN transaction has timed out (PJNATH_ESTUNTIMEDOUT) 17:17:59.274 icetp00 ..Check 3: [2] 79.my.serverIP2:54506-->79.my.serverIP:62203: state changed from In Progress to Failed 17:17:59.274 timer_android. ..Ask to cancel something already fired or cancelled : -1 @ 0x5dc0b400 17:17:59.274 icetp00 ..ICE process complete, status=All ICE checklists failed (PJNATH_EICEFAILED) 17:17:59.274 icetp00 ..Valid list 17:17:59.274 timer_android. ..Scheduling timer 30 of 16 in 0 ms @ 0x5dc0b400 17:17:59.278 stun_session.c .tdata 0x5da8da4c destroy request, force=1, tsx=0x5da8db64 17:17:59.278 timer_android. .Ask to cancel something already fired or cancelled : -1 @ 0x5da8dba4 17:17:59.278 utsx0x5da8db64 .STUN client transaction 0x5da8db64 stopped, ref_cnt=45 17:17:59.278 timer_android. FIRE done and released 17:17:59.289 timer_android. FIRE timer 30 of heap 16 17:17:59.289 icetp00 ICE negotiation failed after 8s:424: All ICE checklists failed (PJNATH_EICEFAILED)
On Tue, Jun 10, 2014 at 3:27 PM, Michael Jerris <mike@jerris.com> wrote:
Its possible that we have some conditions wrong for non-webrtc ice. You are going to need to trace the switch_core_media code a bit and see how we parse the sdp, what we are expecting, and how we turn on ice. I suspect we have conditions that tie some of the ice functionality incorrectly to other things required for webrtc.
On Jun 10, 2014, at 2:09 PM, Jayesh Nambiar <jayesh1017@gmail.com> wrote:
Hi, I am developing an iOS calling App with libnice for ICE capabilities. The calls go through freeswitch and since freeswitch supports ICE, I expected it to work out of the box. But I have a problem. The way libnice works is as follows: 1) The client sends INVITE with his candidates. 2) Freeswitch parses the candidates. 3) Immediately after 200 OK is received, I can see FreeSWITCH choosing an ICE candidate and logging "Activating Audio ICE" indicating the IP and Port and it sends media/RTP to. 4) But the libnice agent tries to look at the candidates received in 200 OK and tries to send a STUN binding request to FreeSWITCH IP as that IP is mentioned as ICE candidate in the 200 OK coming from freeswitch. 5) The FreeSWITCH doesn't respond to that STUN binding request and libnice agent times out. 6) Ideally, if libnice gets back a response from the freeswitch, it should initiate a Re-INVITE with the candidate pair selected.
Now here, the freeswitch starts sending RTP to client's candidate, but the client gets stuck because the candidate pair is not formed as the libnice agent keeps waiting for a response for the STUN Binding Request. Is there anything that I am missing here. Any help is highly appreciated.
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com
FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com
Official FreeSWITCH Sites http://www.freeswitch.org http://wiki.freeswitch.org http://www.cluecon.com
FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com
FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com
Official FreeSWITCH Sites http://www.freeswitch.org http://wiki.freeswitch.org http://www.cluecon.com
FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com
FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com
Official FreeSWITCH Sites http://www.freeswitch.org http://wiki.freeswitch.org http://www.cluecon.com
FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
so that for sure doesn't have the fix i'm thinking in it. Can you try git master on freeswitch and see if that works any better? On Jun 10, 2014, at 8:25 PM, Peter Villeneuve <petervnv1@gmail.com> wrote:
I'm using FreeSWITCH Version 1.5.13b+git~20140515T183425Z~ebc0a99f1c~64bit. Server is on a public IP. What version of CSipSimple did Tony use to test?
There have been some changes recently to ICE in CSip. I'm using latest nightly release (2414) http://nightlies.csipsimple.com/trunk/ with ICE set to aggressive mode.
Also, I have Kamailio in front of FS on the same server, but that shouldn't really be an issue, no?
Anyway, I have some FS logs posted here if you want to take a closer look http://pastebin.com/WNGcpTqB
But I did just confirm that all works as expected with ICE turned off in CSip.
On Tue, Jun 10, 2014 at 9:13 PM, Michael Jerris <mike@jerris.com> wrote: Tony just tested this and it worked with csipsimple. Can you confirm if you are testing with freeswitch from latest git master? is the server side on a public ip or behind nat?
Mike
On Jun 10, 2014, at 5:43 PM, Peter Villeneuve <petervnv1@gmail.com> wrote:
I think Michael's insight appears to be correct. I say this because I also can't seem to get ICE to work correctly with FS when using the CSipSimple client with ICE support.
As you can see in the CSipSimple logs here, it seems that FS fails to correctly respond to the STUN binding request, and thus ICE negotiation fails:
17:17:58.927 icetp00 ..Triggered check for check 1 not performed because it's in progress. Retransmitting 17:17:58.927 utsx0x5dee930c ...STUN sending message (transmit count=7) 17:17:59.040 timer_android. !FIRE timer 26 of heap 16 17:17:59.040 utsx0x5f6e659c STUN timeout waiting for response 17:17:59.040 icetp00 .Check 2: [2] 192.168.1.4:4037-->79.my.serverIP:62203 (nominated): connectivity check FAILED: STUN transaction has timed out (PJNATH_ESTUNTIMEDOUT) 17:17:59.040 icetp00 ..Check 2: [2] 192.168.1.4:4037-->79.my.serverIP:62203: state changed from In Progress to Failed 17:17:59.040 stun_session.c .tdata 0x5f6e6484 destroy request, force=1, tsx=0x5f6e659c 17:17:59.040 timer_android. .Ask to cancel something already fired or cancelled : -1 @ 0x5f6e65dc 17:17:59.040 utsx0x5f6e659c .STUN client transaction 0x5f6e659c stopped, ref_cnt=46 17:17:59.041 timer_android. FIRE done and released 17:17:59.238 timer_android. FIRE timer 27 of heap 16 17:17:59.238 utsx0x5d9a080c STUN timeout waiting for response 17:17:59.238 icetp00 .Check 0: [1] 192.168.1.4:4001-->79.my.serverIP:62202 (nominated): connectivity check FAILED: STUN transaction has timed out (PJNATH_ESTUNTIMEDOUT) 17:17:59.239 icetp00 ..Check 0: [1] 192.168.1.4:4001-->79.my.serverIP:62202: state changed from In Progress to Failed 17:17:59.239 stun_session.c .tdata 0x5d9a06f4 destroy request, force=1, tsx=0x5d9a080c 17:17:59.239 timer_android. .Ask to cancel something already fired or cancelled : -1 @ 0x5d9a084c 17:17:59.239 utsx0x5d9a080c .STUN client transaction 0x5d9a080c stopped, ref_cnt=45 17:17:59.239 timer_android. FIRE done and released 17:17:59.257 timer_android. FIRE timer 28 of heap 16 17:17:59.257 utsx0x5dee930c STUN timeout waiting for response 17:17:59.257 icetp00 .Check 1: [1] 79.my.serverIP:56378-->79.my.serverIP:62202 (nominated): connectivity check FAILED: STUN transaction has timed out (PJNATH_ESTUNTIMEDOUT) 17:17:59.257 icetp00 ..Check 1: [1] 79.my.serverIP:56378-->79.my.serverIP:62202: state changed from In Progress to Failed 17:17:59.258 stun_session.c .tdata 0x5dee91f4 destroy request, force=1, tsx=0x5dee930c 17:17:59.258 timer_android. .Ask to cancel something already fired or cancelled : -1 @ 0x5dee934c 17:17:59.258 utsx0x5dee930c .STUN client transaction 0x5dee930c stopped, ref_cnt=44 17:17:59.258 timer_android. FIRE done and released 17:17:59.273 timer_android. FIRE timer 34 of heap 16 17:17:59.274 utsx0x5da8db64 STUN timeout waiting for response 17:17:59.274 icetp00 .Check 3: [2] 79.my.serverIP2:54506-->79.my.serverIP:62203 (nominated): connectivity check FAILED: STUN transaction has timed out (PJNATH_ESTUNTIMEDOUT) 17:17:59.274 icetp00 ..Check 3: [2] 79.my.serverIP2:54506-->79.my.serverIP:62203: state changed from In Progress to Failed 17:17:59.274 timer_android. ..Ask to cancel something already fired or cancelled : -1 @ 0x5dc0b400 17:17:59.274 icetp00 ..ICE process complete, status=All ICE checklists failed (PJNATH_EICEFAILED) 17:17:59.274 icetp00 ..Valid list 17:17:59.274 timer_android. ..Scheduling timer 30 of 16 in 0 ms @ 0x5dc0b400 17:17:59.278 stun_session.c .tdata 0x5da8da4c destroy request, force=1, tsx=0x5da8db64 17:17:59.278 timer_android. .Ask to cancel something already fired or cancelled : -1 @ 0x5da8dba4 17:17:59.278 utsx0x5da8db64 .STUN client transaction 0x5da8db64 stopped, ref_cnt=45 17:17:59.278 timer_android. FIRE done and released 17:17:59.289 timer_android. FIRE timer 30 of heap 16 17:17:59.289 icetp00 ICE negotiation failed after 8s:424: All ICE checklists failed (PJNATH_EICEFAILED)
On Tue, Jun 10, 2014 at 3:27 PM, Michael Jerris <mike@jerris.com> wrote: Its possible that we have some conditions wrong for non-webrtc ice. You are going to need to trace the switch_core_media code a bit and see how we parse the sdp, what we are expecting, and how we turn on ice. I suspect we have conditions that tie some of the ice functionality incorrectly to other things required for webrtc.
On Jun 10, 2014, at 2:09 PM, Jayesh Nambiar <jayesh1017@gmail.com> wrote:
Hi, I am developing an iOS calling App with libnice for ICE capabilities. The calls go through freeswitch and since freeswitch supports ICE, I expected it to work out of the box. But I have a problem. The way libnice works is as follows: 1) The client sends INVITE with his candidates. 2) Freeswitch parses the candidates. 3) Immediately after 200 OK is received, I can see FreeSWITCH choosing an ICE candidate and logging "Activating Audio ICE" indicating the IP and Port and it sends media/RTP to. 4) But the libnice agent tries to look at the candidates received in 200 OK and tries to send a STUN binding request to FreeSWITCH IP as that IP is mentioned as ICE candidate in the 200 OK coming from freeswitch. 5) The FreeSWITCH doesn't respond to that STUN binding request and libnice agent times out. 6) Ideally, if libnice gets back a response from the freeswitch, it should initiate a Re-INVITE with the candidate pair selected.
Now here, the freeswitch starts sending RTP to client's candidate, but the client gets stuck because the candidate pair is not formed as the libnice agent keeps waiting for a response for the STUN Binding Request. Is there anything that I am missing here. Any help is highly appreciated.
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com
FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com
Official FreeSWITCH Sites http://www.freeswitch.org http://wiki.freeswitch.org http://www.cluecon.com
FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com
FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com
Official FreeSWITCH Sites http://www.freeswitch.org http://wiki.freeswitch.org http://www.cluecon.com
FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com
FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com
Official FreeSWITCH Sites http://www.freeswitch.org http://wiki.freeswitch.org http://www.cluecon.com
FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com
FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com
Official FreeSWITCH Sites http://www.freeswitch.org http://wiki.freeswitch.org http://www.cluecon.com
FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
I used the one from play store. I turned on ice globally and used stun.freeswitch.org for the stun server. OP (Jayesh) You should use wireshark and confirm all the ports and traffic is consistent with what is printed and look to the Chrome ICE as a reference to a working one. You can try http://webrtc.freeswitch.org and compare it to what you get with your client. It will accept blind registrations and allow you to call all the demo extensions with any other sip client as well. Finally, This is not a bug tracker. We ca't be having discussions like this here unless someone wants to help me write a script to convert mailing list threads to JIRAs. On Tue, Jun 10, 2014 at 3:25 PM, Peter Villeneuve <petervnv1@gmail.com> wrote:
I'm using FreeSWITCH Version 1.5.13b+git~20140515T183425Z~ebc0a99f1c~64bit. Server is on a public IP. What version of CSipSimple did Tony use to test?
There have been some changes recently to ICE in CSip. I'm using latest nightly release (2414) http://nightlies.csipsimple.com/trunk/ with ICE set to aggressive mode.
Also, I have Kamailio in front of FS on the same server, but that shouldn't really be an issue, no?
Anyway, I have some FS logs posted here if you want to take a closer look http://pastebin.com/WNGcpTqB
But I did just confirm that all works as expected with ICE turned off in CSip.
On Tue, Jun 10, 2014 at 9:13 PM, Michael Jerris <mike@jerris.com> wrote:
Tony just tested this and it worked with csipsimple. Can you confirm if you are testing with freeswitch from latest git master? is the server side on a public ip or behind nat?
Mike
On Jun 10, 2014, at 5:43 PM, Peter Villeneuve <petervnv1@gmail.com> wrote:
I think Michael's insight appears to be correct. I say this because I also can't seem to get ICE to work correctly with FS when using the CSipSimple client with ICE support.
As you can see in the CSipSimple logs here, it seems that FS fails to correctly respond to the STUN binding request, and thus ICE negotiation fails:
17:17:58.927 icetp00 ..Triggered check for check 1 not performed because it's in progress. Retransmitting 17:17:58.927 utsx0x5dee930c ...STUN sending message (transmit count=7) 17:17:59.040 timer_android. !FIRE timer 26 of heap 16 17:17:59.040 utsx0x5f6e659c STUN timeout waiting for response 17:17:59.040 icetp00 .Check 2: [2] 192.168.1.4:4037-->79.my.serverIP:62203 (nominated): connectivity check FAILED: STUN transaction has timed out (PJNATH_ESTUNTIMEDOUT) 17:17:59.040 icetp00 ..Check 2: [2] 192.168.1.4:4037-->79.my.serverIP:62203: state changed from In Progress to Failed 17:17:59.040 stun_session.c .tdata 0x5f6e6484 destroy request, force=1, tsx=0x5f6e659c 17:17:59.040 timer_android. .Ask to cancel something already fired or cancelled : -1 @ 0x5f6e65dc 17:17:59.040 utsx0x5f6e659c .STUN client transaction 0x5f6e659c stopped, ref_cnt=46 17:17:59.041 timer_android. FIRE done and released 17:17:59.238 timer_android. FIRE timer 27 of heap 16 17:17:59.238 utsx0x5d9a080c STUN timeout waiting for response 17:17:59.238 icetp00 .Check 0: [1] 192.168.1.4:4001-->79.my.serverIP:62202 (nominated): connectivity check FAILED: STUN transaction has timed out (PJNATH_ESTUNTIMEDOUT) 17:17:59.239 icetp00 ..Check 0: [1] 192.168.1.4:4001-->79.my.serverIP:62202: state changed from In Progress to Failed 17:17:59.239 stun_session.c .tdata 0x5d9a06f4 destroy request, force=1, tsx=0x5d9a080c 17:17:59.239 timer_android. .Ask to cancel something already fired or cancelled : -1 @ 0x5d9a084c 17:17:59.239 utsx0x5d9a080c .STUN client transaction 0x5d9a080c stopped, ref_cnt=45 17:17:59.239 timer_android. FIRE done and released 17:17:59.257 timer_android. FIRE timer 28 of heap 16 17:17:59.257 utsx0x5dee930c STUN timeout waiting for response 17:17:59.257 icetp00 .Check 1: [1] 79.my.serverIP:56378-->79.my.serverIP:62202 (nominated): connectivity check FAILED: STUN transaction has timed out (PJNATH_ESTUNTIMEDOUT) 17:17:59.257 icetp00 ..Check 1: [1] 79.my.serverIP:56378-->79.my.serverIP:62202: state changed from In Progress to Failed 17:17:59.258 stun_session.c .tdata 0x5dee91f4 destroy request, force=1, tsx=0x5dee930c 17:17:59.258 timer_android. .Ask to cancel something already fired or cancelled : -1 @ 0x5dee934c 17:17:59.258 utsx0x5dee930c .STUN client transaction 0x5dee930c stopped, ref_cnt=44 17:17:59.258 timer_android. FIRE done and released 17:17:59.273 timer_android. FIRE timer 34 of heap 16 17:17:59.274 utsx0x5da8db64 STUN timeout waiting for response 17:17:59.274 icetp00 .Check 3: [2] 79.my.serverIP2:54506-->79.my.serverIP:62203 (nominated): connectivity check FAILED: STUN transaction has timed out (PJNATH_ESTUNTIMEDOUT) 17:17:59.274 icetp00 ..Check 3: [2] 79.my.serverIP2:54506-->79.my.serverIP:62203: state changed from In Progress to Failed 17:17:59.274 timer_android. ..Ask to cancel something already fired or cancelled : -1 @ 0x5dc0b400 17:17:59.274 icetp00 ..ICE process complete, status=All ICE checklists failed (PJNATH_EICEFAILED) 17:17:59.274 icetp00 ..Valid list 17:17:59.274 timer_android. ..Scheduling timer 30 of 16 in 0 ms @ 0x5dc0b400 17:17:59.278 stun_session.c .tdata 0x5da8da4c destroy request, force=1, tsx=0x5da8db64 17:17:59.278 timer_android. .Ask to cancel something already fired or cancelled : -1 @ 0x5da8dba4 17:17:59.278 utsx0x5da8db64 .STUN client transaction 0x5da8db64 stopped, ref_cnt=45 17:17:59.278 timer_android. FIRE done and released 17:17:59.289 timer_android. FIRE timer 30 of heap 16 17:17:59.289 icetp00 ICE negotiation failed after 8s:424: All ICE checklists failed (PJNATH_EICEFAILED)
On Tue, Jun 10, 2014 at 3:27 PM, Michael Jerris <mike@jerris.com> wrote:
Its possible that we have some conditions wrong for non-webrtc ice. You are going to need to trace the switch_core_media code a bit and see how we parse the sdp, what we are expecting, and how we turn on ice. I suspect we have conditions that tie some of the ice functionality incorrectly to other things required for webrtc.
On Jun 10, 2014, at 2:09 PM, Jayesh Nambiar <jayesh1017@gmail.com> wrote:
Hi, I am developing an iOS calling App with libnice for ICE capabilities. The calls go through freeswitch and since freeswitch supports ICE, I expected it to work out of the box. But I have a problem. The way libnice works is as follows: 1) The client sends INVITE with his candidates. 2) Freeswitch parses the candidates. 3) Immediately after 200 OK is received, I can see FreeSWITCH choosing an ICE candidate and logging "Activating Audio ICE" indicating the IP and Port and it sends media/RTP to. 4) But the libnice agent tries to look at the candidates received in 200 OK and tries to send a STUN binding request to FreeSWITCH IP as that IP is mentioned as ICE candidate in the 200 OK coming from freeswitch. 5) The FreeSWITCH doesn't respond to that STUN binding request and libnice agent times out. 6) Ideally, if libnice gets back a response from the freeswitch, it should initiate a Re-INVITE with the candidate pair selected.
Now here, the freeswitch starts sending RTP to client's candidate, but the client gets stuck because the candidate pair is not formed as the libnice agent keeps waiting for a response for the STUN Binding Request. Is there anything that I am missing here. Any help is highly appreciated.
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com
FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com
Official FreeSWITCH Sites http://www.freeswitch.org http://wiki.freeswitch.org http://www.cluecon.com
FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com
FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com
Official FreeSWITCH Sites http://www.freeswitch.org http://wiki.freeswitch.org http://www.cluecon.com
FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com
FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com
Official FreeSWITCH Sites http://www.freeswitch.org http://wiki.freeswitch.org http://www.cluecon.com
FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com
FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com
Official FreeSWITCH Sites http://www.freeswitch.org http://wiki.freeswitch.org http://www.cluecon.com
FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
-- Anthony Minessale II ♬ @anthmfs ♬ @FreeSWITCH ♬ ☞ http://freeswitch.org/ ☞ http://cluecon.com/ ☞ http://twitter.com/FreeSWITCH ☞ irc.freenode.net #freeswitch ☞ *http://freeswitch.org/g+ <http://freeswitch.org/g+>* ClueCon Weekly Development Call ☎ sip:888@conference.freeswitch.org ☎ +19193869900
I understand this is not jira. I wasn't really sure this was a bug or user error. If indeed it is a bug shouldn't the OP open a jira? I'm about to leave for 1 week, so I won't be able to update to master this week. I'll give it a try next week to see if the issue remains. And the CS in playstore is dated from November. The current nightlies fixed a timing error with ICE a few weeks ago. Maybe that fix broke compatibility with FS? If someone else could test with the latest nightly to confirm the issue, it would be a big help in narrowing down the source of the problem. Cheers, Peter On Tue, Jun 10, 2014 at 9:34 PM, Anthony Minessale < anthony.minessale@gmail.com> wrote:
I used the one from play store. I turned on ice globally and used stun.freeswitch.org for the stun server.
OP (Jayesh) You should use wireshark and confirm all the ports and traffic is consistent with what is printed and look to the Chrome ICE as a reference to a working one. You can try http://webrtc.freeswitch.org and compare it to what you get with your client. It will accept blind registrations and allow you to call all the demo extensions with any other sip client as well.
Finally,
This is not a bug tracker. We ca't be having discussions like this here unless someone wants to help me write a script to convert mailing list threads to JIRAs.
On Tue, Jun 10, 2014 at 3:25 PM, Peter Villeneuve <petervnv1@gmail.com> wrote:
I'm using FreeSWITCH Version 1.5.13b+git~20140515T183425Z~ebc0a99f1c~64bit. Server is on a public IP. What version of CSipSimple did Tony use to test?
There have been some changes recently to ICE in CSip. I'm using latest nightly release (2414) http://nightlies.csipsimple.com/trunk/ with ICE set to aggressive mode.
Also, I have Kamailio in front of FS on the same server, but that shouldn't really be an issue, no?
Anyway, I have some FS logs posted here if you want to take a closer look http://pastebin.com/WNGcpTqB
But I did just confirm that all works as expected with ICE turned off in CSip.
On Tue, Jun 10, 2014 at 9:13 PM, Michael Jerris <mike@jerris.com> wrote:
Tony just tested this and it worked with csipsimple. Can you confirm if you are testing with freeswitch from latest git master? is the server side on a public ip or behind nat?
Mike
On Jun 10, 2014, at 5:43 PM, Peter Villeneuve <petervnv1@gmail.com> wrote:
I think Michael's insight appears to be correct. I say this because I also can't seem to get ICE to work correctly with FS when using the CSipSimple client with ICE support.
As you can see in the CSipSimple logs here, it seems that FS fails to correctly respond to the STUN binding request, and thus ICE negotiation fails:
17:17:58.927 icetp00 ..Triggered check for check 1 not performed because it's in progress. Retransmitting 17:17:58.927 utsx0x5dee930c ...STUN sending message (transmit count=7) 17:17:59.040 timer_android. !FIRE timer 26 of heap 16 17:17:59.040 utsx0x5f6e659c STUN timeout waiting for response 17:17:59.040 icetp00 .Check 2: [2] 192.168.1.4:4037-->79.my.serverIP:62203 (nominated): connectivity check FAILED: STUN transaction has timed out (PJNATH_ESTUNTIMEDOUT) 17:17:59.040 icetp00 ..Check 2: [2] 192.168.1.4:4037-->79.my.serverIP:62203: state changed from In Progress to Failed 17:17:59.040 stun_session.c .tdata 0x5f6e6484 destroy request, force=1, tsx=0x5f6e659c 17:17:59.040 timer_android. .Ask to cancel something already fired or cancelled : -1 @ 0x5f6e65dc 17:17:59.040 utsx0x5f6e659c .STUN client transaction 0x5f6e659c stopped, ref_cnt=46 17:17:59.041 timer_android. FIRE done and released 17:17:59.238 timer_android. FIRE timer 27 of heap 16 17:17:59.238 utsx0x5d9a080c STUN timeout waiting for response 17:17:59.238 icetp00 .Check 0: [1] 192.168.1.4:4001-->79.my.serverIP:62202 (nominated): connectivity check FAILED: STUN transaction has timed out (PJNATH_ESTUNTIMEDOUT) 17:17:59.239 icetp00 ..Check 0: [1] 192.168.1.4:4001-->79.my.serverIP:62202: state changed from In Progress to Failed 17:17:59.239 stun_session.c .tdata 0x5d9a06f4 destroy request, force=1, tsx=0x5d9a080c 17:17:59.239 timer_android. .Ask to cancel something already fired or cancelled : -1 @ 0x5d9a084c 17:17:59.239 utsx0x5d9a080c .STUN client transaction 0x5d9a080c stopped, ref_cnt=45 17:17:59.239 timer_android. FIRE done and released 17:17:59.257 timer_android. FIRE timer 28 of heap 16 17:17:59.257 utsx0x5dee930c STUN timeout waiting for response 17:17:59.257 icetp00 .Check 1: [1] 79.my.serverIP:56378-->79.my.serverIP:62202 (nominated): connectivity check FAILED: STUN transaction has timed out (PJNATH_ESTUNTIMEDOUT) 17:17:59.257 icetp00 ..Check 1: [1] 79.my.serverIP:56378-->79.my.serverIP:62202: state changed from In Progress to Failed 17:17:59.258 stun_session.c .tdata 0x5dee91f4 destroy request, force=1, tsx=0x5dee930c 17:17:59.258 timer_android. .Ask to cancel something already fired or cancelled : -1 @ 0x5dee934c 17:17:59.258 utsx0x5dee930c .STUN client transaction 0x5dee930c stopped, ref_cnt=44 17:17:59.258 timer_android. FIRE done and released 17:17:59.273 timer_android. FIRE timer 34 of heap 16 17:17:59.274 utsx0x5da8db64 STUN timeout waiting for response 17:17:59.274 icetp00 .Check 3: [2] 79.my.serverIP2:54506-->79.my.serverIP:62203 (nominated): connectivity check FAILED: STUN transaction has timed out (PJNATH_ESTUNTIMEDOUT) 17:17:59.274 icetp00 ..Check 3: [2] 79.my.serverIP2:54506-->79.my.serverIP:62203: state changed from In Progress to Failed 17:17:59.274 timer_android. ..Ask to cancel something already fired or cancelled : -1 @ 0x5dc0b400 17:17:59.274 icetp00 ..ICE process complete, status=All ICE checklists failed (PJNATH_EICEFAILED) 17:17:59.274 icetp00 ..Valid list 17:17:59.274 timer_android. ..Scheduling timer 30 of 16 in 0 ms @ 0x5dc0b400 17:17:59.278 stun_session.c .tdata 0x5da8da4c destroy request, force=1, tsx=0x5da8db64 17:17:59.278 timer_android. .Ask to cancel something already fired or cancelled : -1 @ 0x5da8dba4 17:17:59.278 utsx0x5da8db64 .STUN client transaction 0x5da8db64 stopped, ref_cnt=45 17:17:59.278 timer_android. FIRE done and released 17:17:59.289 timer_android. FIRE timer 30 of heap 16 17:17:59.289 icetp00 ICE negotiation failed after 8s:424: All ICE checklists failed (PJNATH_EICEFAILED)
On Tue, Jun 10, 2014 at 3:27 PM, Michael Jerris <mike@jerris.com> wrote:
Its possible that we have some conditions wrong for non-webrtc ice. You are going to need to trace the switch_core_media code a bit and see how we parse the sdp, what we are expecting, and how we turn on ice. I suspect we have conditions that tie some of the ice functionality incorrectly to other things required for webrtc.
On Jun 10, 2014, at 2:09 PM, Jayesh Nambiar <jayesh1017@gmail.com> wrote:
Hi, I am developing an iOS calling App with libnice for ICE capabilities. The calls go through freeswitch and since freeswitch supports ICE, I expected it to work out of the box. But I have a problem. The way libnice works is as follows: 1) The client sends INVITE with his candidates. 2) Freeswitch parses the candidates. 3) Immediately after 200 OK is received, I can see FreeSWITCH choosing an ICE candidate and logging "Activating Audio ICE" indicating the IP and Port and it sends media/RTP to. 4) But the libnice agent tries to look at the candidates received in 200 OK and tries to send a STUN binding request to FreeSWITCH IP as that IP is mentioned as ICE candidate in the 200 OK coming from freeswitch. 5) The FreeSWITCH doesn't respond to that STUN binding request and libnice agent times out. 6) Ideally, if libnice gets back a response from the freeswitch, it should initiate a Re-INVITE with the candidate pair selected.
Now here, the freeswitch starts sending RTP to client's candidate, but the client gets stuck because the candidate pair is not formed as the libnice agent keeps waiting for a response for the STUN Binding Request. Is there anything that I am missing here. Any help is highly appreciated.
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com
FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com
Official FreeSWITCH Sites http://www.freeswitch.org http://wiki.freeswitch.org http://www.cluecon.com
FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE: http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com
FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com
Official FreeSWITCH Sites http://www.freeswitch.org http://wiki.freeswitch.org http://www.cluecon.com
FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com
FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com
Official FreeSWITCH Sites http://www.freeswitch.org http://wiki.freeswitch.org http://www.cluecon.com
FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com
FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com
Official FreeSWITCH Sites http://www.freeswitch.org http://wiki.freeswitch.org http://www.cluecon.com
FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
-- Anthony Minessale II ♬ @anthmfs ♬ @FreeSWITCH ♬
☞ http://freeswitch.org/ ☞ http://cluecon.com/ ☞ http://twitter.com/FreeSWITCH ☞ irc.freenode.net #freeswitch ☞ *http://freeswitch.org/g+ <http://freeswitch.org/g+>*
ClueCon Weekly Development Call ☎ sip:888@conference.freeswitch.org ☎ +19193869900
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com
FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com
Official FreeSWITCH Sites http://www.freeswitch.org http://wiki.freeswitch.org http://www.cluecon.com
FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
participants (4)
-
Anthony Minessale
-
Jayesh Nambiar
-
Michael Jerris
-
Peter Villeneuve