Setting NICE_AGENT_OPTION_ICE_TRICKLE option doesn't postpone changing component state to FAILED
Hi,
it seems that setting NICE_AGENT_OPTION_ICE_TRICKLE to TRUE doesn't postpone changing component state to FAILED.
I didn't invoke nice_agent_peer_candidate_gathering_done() function.
I tried setting NICE_AGENT_OPTION_ICE_TRICKLE in the following ways:
g_object_set (G_OBJECT (agent), "ice-trickle", TRUE, NULL);
or
nice_agent_new_full(g_main_loop_get_context(state->gloop),
NICE_COMPATIBILITY_RFC5245,
NICE_AGENT_OPTION_ICE_TRICKLE);Here are logs. I am using libnice with Elixir in CNode so these lines are a little longer. I replaced my IP addresses with xxxx phrase.
19:02:08.368 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:08.367: Agent 0x5625f3ed70a0: set_remote_candidates 1 1
19:02:08.368 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:08.368: Agent 0x5625f3ed70a0 : Adding UDP remote candidate with addr xxxx for s1/c1. U/P '(null)'/'(null)' prio: 642000ff
19:02:08.369 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:08.368: Agent 0x5625f3ed70a0 : creating a new pair
19:02:08.369 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:08.369: Agent 0x5625f3ed70a0 : pair 0x5625f3eea030 state FROZEN (priv_add_new_check_pair)
19:02:08.369 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:08.369: Agent 0x5625f3ed70a0 : new pair 0x5625f3eea030 : xxxx --> xxxx
19:02:08.369 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:08.369: Unknown sockaddr family: 17
19:02:08.369 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:08.369: Failed to convert address to string for interface ?lo?.
19:02:08.370 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:08.369: Unknown sockaddr family: 17
19:02:08.370 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:08.369: Failed to convert address to string for interface ?eth0?.
19:02:08.370 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:08.369: Interface: lo
19:02:08.370 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:08.369: IP Address: 127.0.0.1
19:02:08.370 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:08.369: Interface: eth0
19:02:08.370 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:08.369: IP Address: xxxx
19:02:08.370 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:08.369: Interface: lo
19:02:08.370 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:08.369: IP Address: ::1
19:02:08.370 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:08.369: Interface: eth0
19:02:08.370 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:08.369: IP Address: xxxx
19:02:08.370 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:08.369: Interface: eth0
19:02:08.370 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:08.369: IP Address: xxxx
19:02:08.370 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:08.369: Agent 0x5625f3ed70a0 : added a new pair 0x5625f3eea030 with foundation '4:7' and transport udp:udp to stream 1 component 1
19:02:08.370 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:08.369: Agent 0x5625f3ed70a0 : stream 1 component 1 STATE-CHANGE gathering -> connecting.
19:02:08.370 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:08.369: Agent 0x5625f3ed70a0 : conn_check_remote_candidates_set 1 1
19:02:08.391 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:08.390: Agent 0x5625f3ed70a0 : Pair 0x5625f3eea030 with s/c-id 1/1 (4:7) unfrozen.
19:02:08.391 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:08.390: Agent 0x5625f3ed70a0 : pair 0x5625f3eea030 state WAITING (priv_conn_check_unfreeze_next)
19:02:08.391 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:08.390: Agent 0x5625f3ed70a0 : *** conncheck list DUMP (called from priv_conn_check_unfreeze_next)
19:02:08.391 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:08.390: Agent 0x5625f3ed70a0 : *** agent nomination mode regular, controlled
19:02:08.391 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:08.390: Agent 0x5625f3ed70a0 : *** sc=1/1 : pair 0x5625f3eea030 : f=4:7 t=host:srflx sock=udp udp:xxxx > udp:xxxx prio=642000ff:782001ff:0/6e2001ff state=W
19:02:08.391 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:08.390: Agent 0x5625f3ed70a0 : pair 0x5625f3eea030 state IN_PROGRESS (priv_conn_check_initiate)
19:02:08.391 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:08.390: Agent 0x5625f3ed70a0 : STUN-CC REQ xxxx --> xxxx, socket=10, pair=0x5625f3eea030 (c-id:1), tie=13681306306651731150, username='Qpr8:bguS' (9), password='b7QDMYYnyfFJArfQC+oUyx' (22), prio=6e2001ff, controlled.
19:02:08.391 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:08.390: Agent 0x5625f3ed70a0 : conn_check_send: set cand_use=0 (regular nomination).
19:02:08.391 [info] cnode#PID<0.302.0>: (process:202248): libnice-stun-DEBUG: 19:02:08.390: Message HMAC-SHA1 message integrity:
19:02:08.391 [info] cnode#PID<0.302.0>: (process:202248): libnice-stun-DEBUG: 19:02:08.391: key : 0x623751444d59596e7966464a41726651432b6f557978
19:02:08.391 [info] cnode#PID<0.302.0>: (process:202248): libnice-stun-DEBUG: 19:02:08.391: sent : 0x011e1fccb2d7a56c25de0f0d3fbb71f25fa037bf
19:02:08.391 [info] cnode#PID<0.302.0>: (process:202248): libnice-stun-DEBUG: 19:02:08.391: Message HMAC-SHA1 fingerprint: 0x80c239c4
19:02:08.391 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:08.391: Agent 0x5625f3ed70a0: conncheck created 88 - 0x7f3f540086a8
19:02:08.392 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:08.391: Agent 0x5625f3ed70a0 : timer set to 500ms, waiting+in_progress=1
19:02:08.392 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:08.391: Agent 0x5625f3ed70a0 : *** conncheck list DUMP (called from priv_conn_check_ordinary_check, initiated an ordinary connection check)
19:02:08.392 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:08.391: Agent 0x5625f3ed70a0 : *** agent nomination mode regular, controlled
19:02:08.392 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:08.391: Agent 0x5625f3ed70a0 : *** sc=1/1 : pair 0x5625f3eea030 : f=4:7 t=host:srflx sock=udp udp:xxxx > udp:xxxx prio=642000ff:782001ff:0/6e2001ff state=I
19:02:08.392 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:08.391: Agent 0x5625f3ed70a0 : *** sc=1/1 : pair 0x5625f3eea030 : stun#=0 timer=1/3 1/500ms buf=0x7f3f540086a8 (R)
19:02:08.392 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:08.391: Agent 0x5625f3ed70a0 : stream 1: timer tick #1: 0 frozen, 1 in-progress, 0 waiting, 0 succeeded, 0 discovered, 0 nominated, 0 waiting-for-nom, 0 valid
19:02:08.393 [info] cnode#PID<0.302.0>: (process:202248): libnice-stun-DEBUG: 19:02:08.392: Message HMAC-SHA1 fingerprint: 0x04bef0ac
19:02:08.393 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:08.392: Agent 0x5625f3ed70a0 : resending STUN to keep the local candidate xxxx alive in s1/c1.
19:02:08.413 [info] cnode#PID<0.302.0>: (process:202248): libnice-stun-DEBUG: 19:02:08.413: Message HMAC-SHA1 fingerprint: 0x2131d496
19:02:08.428 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:08.427: agent_recv_message_unlocked: Agent 0x5625f3ed70a0 : Packet received on local socket 0x5625f3ee5560 (fd 10) from [64.233.161.127]:19302 (32 octets).
19:02:08.428 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:08.427: compact_input_message: **WARNING: SLOW PATH**
19:02:08.428 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:08.427: Message 0x7f3f5c1b8bf0 (from: 0x7f3f5c1b8b30, length: 32)
19:02:08.428 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:08.427: Buffer 0x7f3f5c1b8c50 (length: 65535)
19:02:08.428 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:08.427: Agent 0x5625f3ed70a0: inbound STUN packet for 1/1 (stream/component) from [64.233.161.127]:19302 (32 octets) :
19:02:08.428 [info] cnode#PID<0.302.0>: (process:202248): libnice-stun-DEBUG: 19:02:08.427: STUN demux error: no FINGERPRINT attribute!
19:02:08.428 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:08.427: Agent 0x5625f3ed70a0 : Incorrectly multiplexed STUN message ignored.
19:02:08.428 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:08.427: agent_recv_message_unlocked: Packet passed fast STUN validation but failed slow validation.
19:02:08.428 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:08.427: Agent 0x5625f3ed70a0 : 1:1 DROPPING packet from unknown source 64.233.161.127:19302 sock-type: 0
19:02:08.428 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:08.427: agent_recv_message_unlocked: Agent 0x5625f3ed70a0: no message available on read attempt
19:02:08.428 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:08.427: component_io_cb: 0x5625f3ed70a0: no message available on read attempt
19:02:08.896 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:08.896: Agent 0x5625f3ed70a0 :STUN transaction retransmitted on pair 0x5625f3eea030 (timer=2/3 0/1000ms).
19:02:09.401 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:09.401: Agent 0x5625f3ed70a0 : stream 1: timer tick #51: 0 frozen, 1 in-progress, 0 waiting, 0 succeeded, 0 discovered, 0 nominated, 0 waiting-for-nom, 0 valid
19:02:09.907 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:09.906: Agent 0x5625f3ed70a0 :STUN transaction retransmitted on pair 0x5625f3eea030 (timer=3/3 0/500ms).
19:02:10.412 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:10.412: Agent 0x5625f3ed70a0 : Retransmissions failed, giving up on pair 0x5625f3eea030
19:02:10.413 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:10.412: Agent 0x5625f3ed70a0 : Failed pair is xxxx --> xxxx
19:02:10.413 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:10.413: Agent 0x5625f3ed70a0 : pair 0x5625f3eea030 state FAILED (candidate_check_pair_fail)
19:02:10.413 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:10.413: Agent 0x5625f3ed70a0 : conn.check list status: 0 nominated, 0 valid, c-id 1.
19:02:10.414 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:10.413: Agent 0x5625f3ed70a0 : *** conncheck list DUMP (called from priv_conn_check_tick_stream, retransmission failed)
19:02:10.414 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:10.414: Agent 0x5625f3ed70a0 : *** agent nomination mode regular, controlled
19:02:10.414 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:10.414: Agent 0x5625f3ed70a0 : *** sc=1/1 : pair 0x5625f3eea030 : f=4:7 t=host:srflx sock=udp udp:xxxx > udp:xxxx prio=642000ff:782001ff:0/6e2001ff state=F
19:02:10.414 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:10.414: Agent 0x5625f3ed70a0 : stream 1: timer tick #101: 0 frozen, 0 in-progress, 0 waiting, 0 succeeded, 0 discovered, 0 nominated, 0 waiting-for-nom, 0 valid
19:02:10.415 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:10.415: Agent 0x5625f3ed70a0 : waiting 5000 msecs before checking for failed components.
19:02:11.423 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:11.422: Agent 0x5625f3ed70a0 : stream 1: timer tick #151: 0 frozen, 0 in-progress, 0 waiting, 0 succeeded, 0 discovered, 0 nominated, 0 waiting-for-nom, 0 valid
19:02:12.434 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:12.433: Agent 0x5625f3ed70a0 : stream 1: timer tick #201: 0 frozen, 0 in-progress, 0 waiting, 0 succeeded, 0 discovered, 0 nominated, 0 waiting-for-nom, 0 valid
19:02:13.445 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:13.444: Agent 0x5625f3ed70a0 : stream 1: timer tick #251: 0 frozen, 0 in-progress, 0 waiting, 0 succeeded, 0 discovered, 0 nominated, 0 waiting-for-nom, 0 valid
19:02:14.455 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:14.455: Agent 0x5625f3ed70a0 : stream 1: timer tick #301: 0 frozen, 0 in-progress, 0 waiting, 0 succeeded, 0 discovered, 0 nominated, 0 waiting-for-nom, 0 valid
19:02:15.449 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:15.449: Agent 0x5625f3ed70a0 : checking for failed components now.
19:02:15.450 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:15.450: Agent 0x5625f3ed70a0 : stream 1 component 1 STATE-CHANGE connecting -> failed.
19:02:15.450 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:15.450: Agent 0x5625f3ed70a0 : priv_conn_check_tick_agent_locked: stopping conncheck timer
19:02:15.450 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:15.450: Agent 0x5625f3ed70a0 : *** conncheck list DUMP (called from priv_conn_check_tick_agent_locked, conncheck timer stopped)
19:02:15.450 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:15.450: Agent 0x5625f3ed70a0 : *** agent nomination mode regular, controlled
19:02:15.451 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:15.451: Agent 0x5625f3ed70a0 : *** sc=1/1 : pair 0x5625f3eea030 : f=4:7 t=host:srflx sock=udp udp:xxxx > xxxx prio=642000ff:782001ff:0/6e2001ff state=F
19:02:15.451 [info] cnode#PID<0.302.0>: (process:202248): libnice-DEBUG: 19:02:15.451: Agent 0x5625f3ed70a0 : changing conncheck state to COMPLETED.Thanks in advance!