[Freeswitch-users] STUN Binding request times out after 200 OK received on client

Discussion:

Jayesh Nambiar

2014-06-10 14:09:34 UTC

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
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20140610/fa8c6115/attachment.html

Michael Jerris

2014-06-10 14:27:20 UTC

Permalink

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.

Post by Jayesh Nambiar
Hi,
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.

Peter Villeneuve

2014-06-10 17:43:27 UTC

Permalink

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)

Post by Michael Jerris
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.

Post by Jayesh Nambiar
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

Post by Jayesh Nambiar
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.

Post by Jayesh Nambiar
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.

Post by Jayesh Nambiar
5) The FreeSWITCH doesn't respond to that STUN binding request and

libnice agent times out.

Post by Jayesh Nambiar
6) Ideally, if libnice gets back a response from the freeswitch, it

should initiate a Re-INVITE with the candidate pair selected.

Post by Jayesh Nambiar
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.

Post by Jayesh Nambiar
Is there anything that I am missing here. Any help is highly appreciated.

-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20140610/86c28782/attachment-0001.html

Peter Villeneuve

2014-06-10 19:38:50 UTC

Permalink

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 at gmail.com>

Post by Peter Villeneuve
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
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)
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
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)
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
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
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
17:17:59.274 icetp00 ..ICE process complete, status=All ICE
checklists failed (PJNATH_EICEFAILED)
17:17:59.274 icetp00 ..Valid list
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
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)

Post by Jayesh Nambiar
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

Post by Jayesh Nambiar
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.

Post by Jayesh Nambiar
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.

Post by Jayesh Nambiar
5) The FreeSWITCH doesn't respond to that STUN binding request and

libnice agent times out.

Post by Jayesh Nambiar
6) Ideally, if libnice gets back a response from the freeswitch, it

should initiate a Re-INVITE with the candidate pair selected.

Post by Jayesh Nambiar
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.

Post by Jayesh Nambiar
Is there anything that I am missing here. Any help is highly

appreciated.
_________________________________________________________________________
consulting at 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 at lists.freeswitch.org
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
http://www.freeswitch.org

-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20140610/c7c5e580/attachment-0001.html

Michael Jerris

2014-06-10 20:13:18 UTC

Permalink

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

Post by Peter Villeneuve
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.
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 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 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 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 icetp00 ..ICE process complete, status=All ICE checklists failed (PJNATH_EICEFAILED)
17:17:59.274 icetp00 ..Valid list
17:17:59.278 stun_session.c .tdata 0x5da8da4c destroy request, force=1, tsx=0x5da8db64
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)
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.

_________________________________________________________________________
consulting at 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 at lists.freeswitch.org
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
http://www.freeswitch.org
_________________________________________________________________________
consulting at 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 at lists.freeswitch.org
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
http://www.freeswitch.org

-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20140610/b11ac336/attachment.html

Peter Villeneuve

2014-06-10 20:25:23 UTC

Permalink

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.

Post by Michael Jerris
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
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
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)
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
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)
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
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
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
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.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
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)

Post by Jayesh Nambiar
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

Post by Jayesh Nambiar
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.

Post by Jayesh Nambiar
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.

Post by Jayesh Nambiar
5) The FreeSWITCH doesn't respond to that STUN binding request and

libnice agent times out.

Post by Jayesh Nambiar
6) Ideally, if libnice gets back a response from the freeswitch, it

should initiate a Re-INVITE with the candidate pair selected.

Post by Jayesh Nambiar
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.

Post by Jayesh Nambiar
Is there anything that I am missing here. Any help is highly

-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20140610/b0f66a22/attachment-0001.html

Michael Jerris

2014-06-10 20:33:30 UTC

Permalink

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?

Post by Peter Villeneuve
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.
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

Post by Peter Villeneuve
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.
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 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 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 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 icetp00 ..ICE process complete, status=All ICE checklists failed (PJNATH_EICEFAILED)
17:17:59.274 icetp00 ..Valid list
17:17:59.278 stun_session.c .tdata 0x5da8da4c destroy request, force=1, tsx=0x5da8db64
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)
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.

-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20140610/c385f8ca/attachment-0001.html

Anthony Minessale

2014-06-10 20:34:14 UTC

Permalink

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 at gmail.com>

Post by Peter Villeneuve
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.

Post by Jayesh Nambiar
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

Post by Jayesh Nambiar
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.

Post by Jayesh Nambiar
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.

Post by Jayesh Nambiar
5) The FreeSWITCH doesn't respond to that STUN binding request and

libnice agent times out.

Post by Jayesh Nambiar
6) Ideally, if libnice gets back a response from the freeswitch, it

should initiate a Re-INVITE with the candidate pair selected.

Post by Jayesh Nambiar
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.

Post by Jayesh Nambiar
Is there anything that I am missing here. Any help is highly

--
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 at conference.freeswitch.org ? +19193869900
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20140610/cc46860e/attachment-0001.html

Peter Villeneuve

2014-06-10 20:44:47 UTC

Permalink

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 <

Post by Anthony Minessale
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 at gmail.com>

Post by Peter Villeneuve
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.

Post by Michael Jerris
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
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
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)
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
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)
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
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
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
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.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
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)

Post by Michael Jerris
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.

Post by Jayesh Nambiar
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

Post by Jayesh Nambiar
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.

Post by Jayesh Nambiar
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.

Post by Jayesh Nambiar
5) The FreeSWITCH doesn't respond to that STUN binding request and

libnice agent times out.

Post by Jayesh Nambiar
6) Ideally, if libnice gets back a response from the freeswitch, it

should initiate a Re-INVITE with the candidate pair selected.

Post by Jayesh Nambiar
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.

Post by Jayesh Nambiar
Is there anything that I am missing here. Any help is highly

appreciated.
_________________________________________________________________________
consulting at 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 at lists.freeswitch.org
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
http://lists.freeswitch.org/mailman/options/freeswitch-users
http://www.freeswitch.org

--
? 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 at conference.freeswitch.org ? +19193869900
_________________________________________________________________________
consulting at 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 at lists.freeswitch.org
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
http://www.freeswitch.org

-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20140610/a1882744/attachment-0001.html

Continue reading on narkive:

Search results for '[Freeswitch-users] STUN Binding request times out after 200 OK received on client' (Questions and Answers)

replies

Creating a "Why we should switch to Mac" Speech. Help Please?

started 2007-10-26 15:44:14 UTC

desktops