Video call failed with ICE

What steps will reproduce the problem?
1. I use SIP over TCP with ICE and 3G.
2. I make a video call 

What is the expected output? What do you see instead?
Client does not receive a call. If I make audio call it works fine.

What version of the product are you using? On what operating system?
latest doubango used for iOS

Please provide any additional information below.

Video call log:

SSL is enabled :)
DTLS supported: yes
DTLS-SRTP supported: yes
2013-04-04 17:09:52.960 VideoCall[7699:4603] NgnEngine///: dummyCoCoaThread()
2013-04-04 17:09:53.010 VideoCall[7699:907] NgnEngine///: Working in 
multithreaded mode :)
2013-04-04 17:09:53.017 VideoCall[7699:907] NgnConfigurationService///: Start()
2013-04-04 17:09:53.028 VideoCall[7699:907] NgnNetworkService///: Start()
2013-04-04 17:09:53.053 VideoCall[7699:907] NgnStorageService///: Start()
2013-04-04 17:09:53.061 VideoCall[7699:907] NgnStorageService///: 
databasePath:/var/mobile/Applications/90BD90E6-8E42-4595-A0A6-6F0BF72D5F41/Docum
ents/NgnDataBase.db
2013-04-04 17:09:53.073 VideoCall[7699:907] NgnStorageService///: found 
databaseVersion=0
2013-04-04 17:09:53.081 VideoCall[7699:907] NgnStorageService///: used 
databaseVersion=0
2013-04-04 17:09:53.087 VideoCall[7699:907] NgnStorageService///: No changes: 
database v-current=0
2013-04-04 17:09:53.100 VideoCall[7699:907] NgnContactService///: Start()
2013-04-04 17:09:53.268 VideoCall[7699:907] NgnSipService///: Start()
2013-04-04 17:09:53.272 VideoCall[7699:907] NgnHttpClientService///: Start()
2013-04-04 17:09:53.277 VideoCall[7699:907] NgnHistoryService///: Start()
2013-04-04 17:09:53.286 VideoCall[7699:907] NgnSoundService///: Start()
2013-04-04 17:09:53.561 VideoCall[7699:907] NgnSipService///: register()
2013-04-04 17:09:53.566 VideoCall[7699:907] NgnSipService///: realm='*.*.*.*', 
impu='sip:3235@*.*.*.*', impi='3235'
*INFO: Calling 'tnet_dns_resolvconf_parse()' to load DNS servers
*INFO: Failed to open [/etc/resolv.conf]. But don't panic, we have detected 
that you are using Google Android/iOS Systems.
You should look at the Progammer's Guide for more information.
 If you are not using DNS functions, don't worry about this warning.
2013-04-04 17:09:53.593 VideoCall[7699:907] NgnSipService///: STUN=no
2013-04-04 17:09:53.598 VideoCall[7699:907] NgnSipService///: 
pcscf-host='*.*.*.*', pcscf-port='5060', transport='tcp', ipversion='ipv4'
*INFO: Stack running in CLIENT mode
*INFO: tsk_timer_manager_start
*INFO: Proxy-CSCF=[*.*.*.*]:5060
*INFO: Socket added
*INFO: Socket added
*INFO: Timer manager run()::enter
*INFO: SIP STACK::run -- START
*INFO: Transport::run() - enter
*INFO: TIMER MANAGER -- START
*INFO: Starting [SIP transport] server with IP {46.191.76.29} on port {61240}...
*INFO: __CFReadStreamClientCallBack --> kCFStreamEventOpenCompleted
*INFO: __CFWriteStreamClientCallBack --> kCFStreamEventOpenCompleted
*INFO: __CFReadStreamClientCallBack --> kCFStreamEventOpenCompleted
*INFO: __CFWriteStreamClientCallBack --> kCFStreamEventOpenCompleted
*INFO: Stream Peer accepted/connected - 14
*INFO: Stream Peer accepted/connected - 14
*INFO: Stream Peer accepted/connected - 16
*INFO: Stream Peer accepted/connected - 16
*INFO: SIP STACK -- START
*INFO: State machine: tsip_dialog_register_Started_2_InProgress_X_oRegister
*INFO: State machine: tsip_transac_nict_Started_2_Trying_X_send
2013-04-04 17:09:53.872 VideoCall[7699:5803] NgnSipService///: Stack started
*INFO: OnDialogEvent(Dialog connecting, 1)

RECV:SIP/2.0 200 OK
Via: SIP/2.0/TCP 46.191.76.29:61241;rport=61241;branch=z9hG4bK236868883
From: <sip:3235@*.*.*.*>;tag=307669825
To: <sip:3235@*.*.*.*>;tag=f251698a449604a8e959b300b5a3ea81.3acc
Call-ID: 9bfe1c33-a98c-dd4c-e8b5-b89b0644afff
CSeq: 958687534 REGISTER
Contact: <sip:3235@46.191.76.29:61036;transport=tcp>;expires=2350
Contact: <sip:3235@46.191.76.29:61101;transport=tcp>;expires=2469
Contact: <sip:3235@46.191.76.29:61137;transport=tcp>;expires=2755
Contact: <sip:3235@46.191.76.29:61241;transport=tcp>;expires=3200
Server: kamailio (4.0.0 (x86_64/linux))
Content-Length: 0

*INFO: State machine: tsip_transac_nict_Trying_2_Completed_X_200_to_699
*INFO: State machine: tsip_dialog_register_InProgress_2_Connected_X_2xx
*INFO: OnDialogEvent(Dialog connected, 1)
*INFO: State machine: tsip_transac_nict_Completed_2_Terminated_X_timerK
*INFO: === NICT terminated ===
*INFO: *** NICT destroyed ***
*INFO: State machine: x0500_Current_2_Current_X_oINVITE
*INFO: tsk_timer_manager_start
*INFO: tsk_timer_manager_start
*INFO: Timer manager run()::enter
*INFO: ICE CTX::run -- START
*INFO: Timer manager run()::enter
*INFO: ICE CTX::run -- START
*INFO: OnDialogEvent(Dialog connecting, 2)
*INFO: TIMER MANAGER -- START
*INFO: TIMER MANAGER -- START
*INFO: RTP/RTCP manager[Begin]: Trying to bind to random ports 
[46.191.76.29:54696]
*INFO: RTP/RTCP manager[End]: Trying to bind to random ports
*INFO: local ip address = 46.191.76.29
*INFO: ICE callback: Gathering host candidates succeed
*INFO: RTP/RTCP manager[Begin]: Trying to bind to random ports 
[46.191.76.29:64072]
*INFO: RTP/RTCP manager[End]: Trying to bind to random ports
*INFO: local ip address = 46.191.76.29
*INFO: ICE callback: Gathering host candidates succeed
*INFO: Skipping redundant candidate address=46.191.76.29 and port=54697
*INFO: Candidate: 8MHPRXMo0 1 udp 2130706431 46.191.76.29 54696 typ host
*INFO: Candidate: 8MHPRXMo0 2 udp 2130706430 46.191.76.29 54697 typ host
*INFO: === ICE CTX SM Terminated ===
*INFO: ICE callback: Gathering reflexive candidates failed
*INFO: State machine: x0500_Current_2_Current_X_oINVITE
*INFO: ICE restart
*INFO: ICE already started
*INFO: ICE already started
*INFO: Skipping redundant candidate address=46.191.76.29 and port=64072
*INFO: Skipping redundant candidate address=46.191.76.29 and port=64073
*INFO: Candidate: mc6HnV1uF 1 udp 2130706431 46.191.76.29 64072 typ host
*INFO: Candidate: mc6HnV1uF 2 udp 2130706430 46.191.76.29 64073 typ host
*INFO: === ICE CTX SM Terminated ===
*INFO: ICE callback: Gathering reflexive candidates failed
*INFO: OnDialogEvent(Dialog connecting, 2)
*INFO: RTP/RTCP manager[Begin]: Trying to bind to random ports 
[46.191.76.29:49610]
*INFO: RTP/RTCP manager[End]: Trying to bind to random ports
*INFO: local ip address = 46.191.76.29
*INFO: ICE callback: Gathering host candidates succeed
*INFO: Skipping redundant candidate address=46.191.76.29 and port=49610
*INFO: Skipping redundant candidate address=46.191.76.29 and port=49611
*INFO: Candidate: GtZTwk5Tm 1 udp 2130706431 46.191.76.29 49610 typ host
*INFO: Candidate: GtZTwk5Tm 2 udp 2130706430 46.191.76.29 49611 typ host
*INFO: === ICE CTX SM Terminated ===
*INFO: ICE callback: Gathering reflexive candidates failed

Audio call log:

SSL is enabled :)
DTLS supported: yes
DTLS-SRTP supported: yes
2013-04-04 17:15:10.655 VideoCall[7733:4503] NgnEngine///: dummyCoCoaThread()
2013-04-04 17:15:10.662 VideoCall[7733:907] NgnEngine///: Working in 
multithreaded mode :)
2013-04-04 17:15:10.667 VideoCall[7733:907] NgnConfigurationService///: Start()
2013-04-04 17:15:10.674 VideoCall[7733:907] NgnNetworkService///: Start()
2013-04-04 17:15:10.695 VideoCall[7733:907] NgnStorageService///: Start()
2013-04-04 17:15:10.701 VideoCall[7733:907] NgnStorageService///: 
databasePath:/var/mobile/Applications/90BD90E6-8E42-4595-A0A6-6F0BF72D5F41/Docum
ents/NgnDataBase.db
2013-04-04 17:15:10.710 VideoCall[7733:907] NgnStorageService///: found 
databaseVersion=0
2013-04-04 17:15:10.715 VideoCall[7733:907] NgnStorageService///: used 
databaseVersion=0
2013-04-04 17:15:10.719 VideoCall[7733:907] NgnStorageService///: No changes: 
database v-current=0
2013-04-04 17:15:10.728 VideoCall[7733:907] NgnContactService///: Start()
2013-04-04 17:15:10.949 VideoCall[7733:907] NgnSipService///: Start()
2013-04-04 17:15:10.955 VideoCall[7733:907] NgnHttpClientService///: Start()
2013-04-04 17:15:10.959 VideoCall[7733:907] NgnHistoryService///: Start()
2013-04-04 17:15:10.965 VideoCall[7733:907] NgnSoundService///: Start()
2013-04-04 17:15:11.460 VideoCall[7733:907] NgnSipService///: register()
2013-04-04 17:15:11.465 VideoCall[7733:907] NgnSipService///: realm='*.*.*.*', 
impu='sip:3235@*.*.*.*', impi='3235'
*INFO: Calling 'tnet_dns_resolvconf_parse()' to load DNS servers
*INFO: Failed to open [/etc/resolv.conf]. But don't panic, we have detected 
that you are using Google Android/iOS Systems.
You should look at the Progammer's Guide for more information.
 If you are not using DNS functions, don't worry about this warning.
2013-04-04 17:15:11.490 VideoCall[7733:907] NgnSipService///: STUN=no
2013-04-04 17:15:11.492 VideoCall[7733:907] NgnSipService///: 
pcscf-host='*.*.*.*', pcscf-port='5060', transport='tcp', ipversion='ipv4'
*INFO: Stack running in CLIENT mode
*INFO: tsk_timer_manager_start
*INFO: Proxy-CSCF=[*.*.*.*]:5060
*INFO: Socket added
*INFO: Socket added
*INFO: Timer manager run()::enter
*INFO: SIP STACK::run -- START
*INFO: Transport::run() - enter
*INFO: TIMER MANAGER -- START
*INFO: Starting [SIP transport] server with IP {46.191.76.29} on port {61309}...
[Switching to process 9255 thread 0x2427]
*INFO: __CFReadStreamClientCallBack --> kCFStreamEventOpenCompleted
*INFO: __CFWriteStreamClientCallBack --> kCFStreamEventOpenCompleted
*INFO: __CFReadStreamClientCallBack --> kCFStreamEventOpenCompleted
*INFO: __CFWriteStreamClientCallBack --> kCFStreamEventOpenCompleted
*INFO: Stream Peer accepted/connected - 14
*INFO: Stream Peer accepted/connected - 14
*INFO: Stream Peer accepted/connected - 16
*INFO: Stream Peer accepted/connected - 16
*INFO: SIP STACK -- START
*INFO: State machine: tsip_dialog_register_Started_2_InProgress_X_oRegister
*INFO: State machine: tsip_transac_nict_Started_2_Trying_X_send
2013-04-04 17:15:11.764 VideoCall[7733:5603] NgnSipService///: Stack started
*INFO: OnDialogEvent(Dialog connecting, 1)
*INFO: OnDialogEvent((un)REGISTER request successfully sent., 1)
*INFO: 

RECV:SIP/2.0 200 OK
Via: SIP/2.0/TCP 46.191.76.29:61310;rport=61310;branch=z9hG4bK21028202
From: <sip:3235@*.*.*.*>;tag=1717658498
To: <sip:3235@*.*.*.*>;tag=f251698a449604a8e959b300b5a3ea81.159c
Call-ID: c8a849ad-a3ab-1992-7033-a17135944073
CSeq: 1849271240 REGISTER
Contact: <sip:3235@46.191.76.29:61036;transport=tcp>;expires=2032
Contact: <sip:3235@46.191.76.29:61101;transport=tcp>;expires=2151
Contact: <sip:3235@46.191.76.29:61137;transport=tcp>;expires=2437
Contact: <sip:3235@46.191.76.29:61241;transport=tcp>;expires=2882
Contact: <sip:3235@46.191.76.29:61310;transport=tcp>;expires=3200
Server: kamailio (4.0.0 (x86_64/linux))
Content-Length: 0

*INFO: State machine: tsip_transac_nict_Trying_2_Completed_X_200_to_699
*INFO: State machine: tsip_dialog_register_InProgress_2_Connected_X_2xx
*INFO: OnDialogEvent(Dialog connected, 1)
*INFO: State machine: tsip_transac_nict_Completed_2_Terminated_X_timerK
*INFO: === NICT terminated ===
*INFO: *** NICT destroyed ***
*INFO: State machine: x0500_Current_2_Current_X_oINVITE
*INFO: tsk_timer_manager_start
*INFO: Timer manager run()::enter
*INFO: ICE CTX::run -- START
*INFO: OnDialogEvent(Dialog connecting, 2)
*INFO: TIMER MANAGER -- START
*INFO: RTP/RTCP manager[Begin]: Trying to bind to random ports 
[46.191.76.29:57978]
*INFO: RTP/RTCP manager[End]: Trying to bind to random ports
*INFO: local ip address = 46.191.76.29
*INFO: ICE callback: Gathering host candidates succeed
*INFO: Skipping redundant candidate address=46.191.76.29 and port=57978
*INFO: Candidate: TePK9MGPh 1 udp 2130706431 46.191.76.29 57978 typ host
*INFO: Candidate: TePK9MGPh 2 udp 2130706430 46.191.76.29 57979 typ host
*INFO: === ICE CTX SM Terminated ===
*INFO: ICE callback: Gathering reflexive candidates failed
*INFO: State machine: c0000_Started_2_Outgoing_X_oINVITE
*INFO: tdav_consumer_audio_init()
*INFO: Create SpeexDSP jitter buffer
WARNING: no real random source present!
*INFO: ICE enabled on RTP manager
*INFO: OnDialogEvent(Dialog connecting, 2)
*INFO: 

RECV:SIP/2.0 100 trying -- your call is important to us
Via: SIP/2.0/TCP 46.191.76.29:61310;rport=61310;branch=z9hG4bK708749688
From: <sip:3235@*.*.*.*>;tag=1655409876
To: <sip:6052@*.*.*.*>
Call-ID: cceb88d9-ebcb-d042-9ba9-9ce66322adaf
CSeq: 1321227155 INVITE
Server: kamailio (4.0.0 (x86_64/linux))
Content-Length: 0

SIP/2.0 180 Ringing
From: <sip:3235@*.*.*.*>;tag=1655409876
To: <sip:6052@*.*.*.*>;tag=987905813
Contact: <sip:6052@192.168.1.20:58612;transport=tcp;alias=37.45.207.134~29400~2>
Call-ID: cceb88d9-ebcb-d042-9ba9-9ce66322adaf
CSeq: 1321227155 INVITE
Via: SIP/2.0/TCP 46.191.76.29:61310;rport=61310;branch=z9hG4bK708749688
Record-Route: <sip:192.168.7.24;transport=tcp;lr;nat=yes>
Require: 100rel
RSeq: 1450721731
Allow: ACK, BYE, CANCEL, INVITE, MESSAGE, NOTIFY, OPTIONS, PRACK, REFER, UPDATE
Content-Length: 0

*INFO: State machine: x0000_Any_2_Any_X_i1xx
*INFO: State machine: x0000_Any_2_Any_X_i1xx
*INFO: State machine: tsip_transac_nict_Started_2_Trying_X_send
*INFO: 

RECV:SIP/2.0 180 Ringing
From: <sip:3235@*.*.*.*>;tag=1655409876
To: <sip:6052@*.*.*.*>;tag=987905813
Contact: <sip:6052@192.168.1.20:58612;transport=tcp;alias=37.45.207.134~29400~2>
Call-ID: cceb88d9-ebcb-d042-9ba9-9ce66322adaf
CSeq: 1321227155 INVITE
Via: SIP/2.0/TCP 46.191.76.29:61310;rport=61310;branch=z9hG4bK708749688
Record-Route: <sip:192.168.7.24;transport=tcp;lr;nat=yes>
Require: 100rel
RSeq: 1450721731
Allow: ACK, BYE, CANCEL, INVITE, MESSAGE, NOTIFY, OPTIONS, PRACK, REFER, UPDATE
Content-Length: 0

*INFO: State machine: x0000_Any_2_Any_X_i1xx
**WARN: function: "send_PRACK()" 
file: "/../doubango/tinySIP/src/dialogs/tsip_dialog_invite.c" 
line: "1181" 
MSG: 1xx.RSeq value is not one higher than lastINVITE.RSeq.
*INFO: 

RECV:SIP/2.0 180 Ringing
From: <sip:3235@*.*.*.*>;tag=1655409876
To: <sip:6052@*.*.*.*>;tag=987905813
Contact: <sip:6052@192.168.1.20:58612;transport=tcp;alias=37.45.207.134~29400~2>
Call-ID: cceb88d9-ebcb-d042-9ba9-9ce66322adaf
CSeq: 1321227155 INVITE
Via: SIP/2.0/TCP 46.191.76.29:61310;rport=61310;branch=z9hG4bK708749688
Record-Route: <sip:192.168.7.24;transport=tcp;lr;nat=yes>
Require: 100rel
RSeq: 1450721731
Allow: ACK, BYE, CANCEL, INVITE, MESSAGE, NOTIFY, OPTIONS, PRACK, REFER, UPDATE
Content-Length: 0

*INFO: State machine: x0000_Any_2_Any_X_i1xx
**WARN: function: "send_PRACK()" 
file: "/../doubango/tinySIP/src/dialogs/tsip_dialog_invite.c" 
line: "1181" 
MSG: 1xx.RSeq value is not one higher than lastINVITE.RSeq.
*INFO: 

RECV:SIP/2.0 200 OK
From: <sip:3235@*.*.*.*>;tag=1655409876
To: <sip:6052@*.*.*.*>;tag=987905813
Contact: <sip:6052@192.168.1.20:58612;transport=tcp;alias=37.45.207.134~29400~2>
Call-ID: cceb88d9-ebcb-d042-9ba9-9ce66322adaf
CSeq: 1321227155 INVITE
Via: SIP/2.0/TCP 46.191.76.29:61310;rport=61310;branch=z9hG4bK708749688
Record-Route: <sip:192.168.7.24;transport=tcp;lr;nat=yes>
Allow: ACK, BYE, CANCEL, INVITE, MESSAGE, NOTIFY, OPTIONS, PRACK, REFER, UPDATE
Content-Type: application/sdp
Content-Length: 697

v=0
o=doubango 1983 678901 IN IP4 192.168.1.20
s=-
c=IN IP4 192.168.1.20
t=0 0
m=audio 54330 RTP/AVP 101 8 97
c=IN IP4 192.168.1.20
a=ptime:20
a=silenceSupp:off - - - -
a=rtpmap:101 telephone-event/8000/1
a=fmtp:101 0-16
a=rtpmap:8 PCMA/8000/1
a=rtpmap:97 SPEEX/8000/1
a=acfg:1 t=1
a=sendrecv
a=rtcp-mux
a=ssrc:2583680202 cname:ldjWoB60jbyQlR6e
a=ssrc:2583680202 mslabel:6994f7d1-6ce9-4fbd-acfd-84e5131ca2e2
a=ssrc:2583680202 label:Doubango.Audio
a=ice-ufrag:70sr6CKnphKbNOk
a=ice-pwd:dEemgUTWWGGzE2Vu4ucKf
a=candidate:3iVmhWO28 1 udp 2130706431 192.168.1.20 54330 typ host
a=candidate:srflx3iVm 1 udp 1694498815 37.45.207.134 29409 typ srflx raddr 
192.168.1.20 rport 54330

*INFO: State machine: c0000_Outgoing_2_Connected_X_i2xxINVITE
*INFO: tnet_ice_ctx_set_remote_candidates
*INFO: is_ro_provisional_final_matching=0,
is_ro_media_lines_changed=0,
is_ro_network_info_changed=0,
is_ro_loopback_address=0,
is_media_type_changed=0

*INFO: Remote SSRC = 2583680202
*INFO: SO_RCVBUF = 131070, SO_SNDBUF = 131070
*INFO: tsk_timer_manager_start
*INFO: Timer manager already running
*INFO: Socket added
*INFO: Transport::run() - enter
*INFO: Starting [RTP/RTCP Manager] server with IP {46.191.76.29} on port 
{57978}...
Original issue reported on code.google.com by denis.tr...@gmail.com on 4 Apr 2013 at 2:29
zighouse / doubango

Video call failed with ICE #230
