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

Tue Jun 10 21:43:27 MSD 2014

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 at 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 at 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 at freeswitch.org
> http://www.freeswitchsolutions.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/86c28782/attachment-0001.html 