Fixed misc bugs with ICE: (1) moved STUN session from candidate to component since it causes STUN response to wrong session, and (2) keep-alive transaction timed-out when ICE is active

git-svn-id: http://svn.pjsip.org/repos/pjproject/trunk@1140 74dad513-b988-da41-8d7b-12977e46ad98

4 files changed, 307 insertions, 146 deletions

diff --git a/pjnath/src/pjnath/ice_session.c b/pjnath/src/pjnath/ice_session.c
index 5365ca6a..f3b9ce87 100644
--- a/pjnath/src/pjnath/ice_session.c
+++ b/pjnath/src/pjnath/ice_session.c
@@ -83,7 +83,8 @@ static pj_uint8_t cand_type_prefs[4] =
 typedef struct stun_data
 {
     pj_ice_sess		*ice;
-    pj_ice_sess_cand	*lcand;
+    unsigned		 comp_id;
+    pj_ice_sess_comp	*comp;
 } stun_data;
 
 typedef struct timer_data
@@ -179,6 +180,50 @@ PJ_DEF(void) pj_ice_calc_foundation(pj_pool_t *pool,
 }
 
 
+/* Init component */
+static pj_status_t init_comp(pj_ice_sess *ice,
+			     unsigned comp_id,
+			     pj_ice_sess_comp *comp)
+{
+    pj_stun_session_cb sess_cb;
+    pj_stun_auth_cred auth_cred;
+    stun_data *sd;
+    pj_status_t status;
+
+    /* Init STUN callbacks */
+    pj_bzero(&sess_cb, sizeof(sess_cb));
+    sess_cb.on_request_complete = &on_stun_request_complete;
+    sess_cb.on_rx_indication = &on_stun_rx_indication;
+    sess_cb.on_rx_request = &on_stun_rx_request;
+    sess_cb.on_send_msg = &on_stun_send_msg;
+
+    /* Create STUN session for this candidate */
+    status = pj_stun_session_create(&ice->stun_cfg, NULL, 
+			            &sess_cb, PJ_FALSE,
+				    &comp->stun_sess);
+    if (status != PJ_SUCCESS)
+	return status;
+
+    /* Associate data with this STUN session */
+    sd = PJ_POOL_ZALLOC_T(ice->pool, struct stun_data);
+    sd->ice = ice;
+    sd->comp_id = comp_id;
+    sd->comp = comp;
+    pj_stun_session_set_user_data(comp->stun_sess, sd);
+
+    /* Init STUN authentication credential */
+    pj_bzero(&auth_cred, sizeof(auth_cred));
+    auth_cred.type = PJ_STUN_AUTH_CRED_DYNAMIC;
+    auth_cred.data.dyn_cred.get_auth = &stun_auth_get_auth;
+    auth_cred.data.dyn_cred.get_cred = &stun_auth_get_cred;
+    auth_cred.data.dyn_cred.get_password = &stun_auth_get_password;
+    auth_cred.data.dyn_cred.user_data = comp->stun_sess;
+    pj_stun_session_set_credential(comp->stun_sess, &auth_cred);
+
+    return PJ_SUCCESS;
+}
+
+
 /*
  * Create ICE session.
  */
@@ -227,11 +272,18 @@ PJ_DEF(pj_status_t) pj_ice_sess_create(pj_stun_config *stun_cfg,
 	pj_ice_sess_comp *comp;
 	comp = &ice->comp[i];
 	comp->valid_check = NULL;
+
+	status = init_comp(ice, i+1, comp);
+	if (status != PJ_SUCCESS) {
+	    destroy_ice(ice, status);
+	    return status;
+	}
     }
 
     if (local_ufrag == NULL) {
 	ice->rx_ufrag.ptr = pj_pool_alloc(ice->pool, 16);
 	pj_create_random_string(ice->rx_ufrag.ptr, 16);
+	ice->rx_ufrag.slen = 16;
     } else {
 	pj_strdup(ice->pool, &ice->rx_ufrag, local_ufrag);
     }
@@ -239,6 +291,7 @@ PJ_DEF(pj_status_t) pj_ice_sess_create(pj_stun_config *stun_cfg,
     if (local_passwd == NULL) {
 	ice->rx_pass.ptr = pj_pool_alloc(ice->pool, 16);
 	pj_create_random_string(ice->rx_pass.ptr, 16);
+	ice->rx_pass.slen = 16;
     } else {
 	pj_strdup(ice->pool, &ice->rx_pass, local_passwd);
     }
@@ -267,10 +320,10 @@ static void destroy_ice(pj_ice_sess *ice,
 	LOG4((ice->obj_name, "Destroying ICE session"));
     }
 
-    for (i=0; i<ice->lcand_cnt; ++i) {
-	if (ice->lcand[i].stun_sess) {
-	    pj_stun_session_destroy(ice->lcand[i].stun_sess);
-	    ice->lcand[i].stun_sess = NULL;
+    for (i=0; i<ice->comp_cnt; ++i) {
+	if (ice->comp[i].stun_sess) {
+	    pj_stun_session_destroy(ice->comp[i].stun_sess);
+	    ice->comp[i].stun_sess = NULL;
 	}
     }
 
@@ -465,9 +518,6 @@ PJ_DEF(pj_status_t) pj_ice_sess_add_cand(pj_ice_sess *ice,
 					 unsigned *p_cand_id)
 {
     pj_ice_sess_cand *lcand;
-    pj_stun_session_cb sess_cb;
-    pj_stun_auth_cred auth_cred;
-    stun_data *sd;
     pj_status_t status = PJ_SUCCESS;
     char tmp[128];
 
@@ -496,38 +546,6 @@ PJ_DEF(pj_status_t) pj_ice_sess_add_cand(pj_ice_sess *ice,
 	pj_bzero(&lcand->rel_addr, sizeof(lcand->rel_addr));
 
 
-    /* Init STUN callbacks */
-    pj_bzero(&sess_cb, sizeof(sess_cb));
-    sess_cb.on_request_complete = &on_stun_request_complete;
-    sess_cb.on_rx_indication = &on_stun_rx_indication;
-    sess_cb.on_rx_request = &on_stun_rx_request;
-    sess_cb.on_send_msg = &on_stun_send_msg;
-
-    /* Create STUN session for this candidate */
-    status = pj_stun_session_create(&ice->stun_cfg, ice->obj_name, 
-			            &sess_cb, PJ_FALSE,
-				    &lcand->stun_sess);
-    if (status != PJ_SUCCESS) {
-	pj_mutex_unlock(ice->mutex);
-	return status;
-    }
-
-    /* Associate data with this STUN session */
-    sd = PJ_POOL_ZALLOC_T(ice->pool, struct stun_data);
-    sd->ice = ice;
-    sd->lcand = lcand;
-    pj_stun_session_set_user_data(lcand->stun_sess, sd);
-
-    /* Init STUN authentication credential */
-    pj_bzero(&auth_cred, sizeof(auth_cred));
-    auth_cred.type = PJ_STUN_AUTH_CRED_DYNAMIC;
-    auth_cred.data.dyn_cred.get_auth = &stun_auth_get_auth;
-    auth_cred.data.dyn_cred.get_cred = &stun_auth_get_cred;
-    auth_cred.data.dyn_cred.get_password = &stun_auth_get_password;
-    auth_cred.data.dyn_cred.user_data = lcand->stun_sess;
-    pj_stun_session_set_credential(lcand->stun_sess, &auth_cred);
-
-
     pj_ansi_strcpy(tmp, pj_inet_ntoa(lcand->addr.ipv4.sin_addr));
     LOG4((ice->obj_name, 
 	 "Candidate %d added: comp_id=%d, type=%s, foundation=%.*s, "
@@ -908,6 +926,8 @@ static pj_bool_t on_check_complete(pj_ice_sess *ice,
 	LOG5((ice->obj_name, "Check %d is successful and nominated",
 	     GET_CHECK_ID(&ice->clist, check)));
 
+	comp = find_comp(ice, check->lcand->comp_id);
+
 	for (i=0; i<ice->clist.count; ++i) {
 	    pj_ice_sess_check *c = &ice->clist.checks[i];
 	    if (c->lcand->comp_id == check->lcand->comp_id) {
@@ -926,7 +946,7 @@ static pj_bool_t on_check_complete(pj_ice_sess *ice,
 			LOG5((ice->obj_name, 
 			     "Cancelling check %s (In Progress)",
 			     dump_check(buf, sizeof(buf), &ice->clist, c)));
-			pj_stun_session_cancel_req(c->lcand->stun_sess, 
+			pj_stun_session_cancel_req(comp->stun_sess, 
 						   c->tdata, PJ_FALSE, 0);
 			c->tdata = NULL;
 			check_set_state(ice, c, PJ_ICE_SESS_CHECK_STATE_FAILED,
@@ -937,7 +957,6 @@ static pj_bool_t on_check_complete(pj_ice_sess *ice,
 	}
 
 	/* Update the nominated check for the component */
-	comp = find_comp(ice, check->lcand->comp_id);
 	if (comp->valid_check == NULL) {
 	    comp->valid_check = check;
 	} else {
@@ -1164,9 +1183,9 @@ static pj_status_t perform_check(pj_ice_sess *ice,
 	 dump_check(buffer, sizeof(buffer), clist, check)));
 
     /* Create request */
-    status = pj_stun_session_create_req(lcand->stun_sess, 
+    status = pj_stun_session_create_req(comp->stun_sess, 
 					PJ_STUN_BINDING_REQUEST, 
-					&check->tdata);
+					NULL, &check->tdata);
     if (status != PJ_SUCCESS) {
 	pjnath_perror(ice->obj_name, "Error creating STUN request", status);
 	return status;
@@ -1199,7 +1218,7 @@ static pj_status_t perform_check(pj_ice_sess *ice,
      */
 
     /* Initiate STUN transaction to send the request */
-    status = pj_stun_session_send_msg(lcand->stun_sess, PJ_FALSE, 
+    status = pj_stun_session_send_msg(comp->stun_sess, PJ_FALSE, 
 				      &rcand->addr, 
 				      sizeof(pj_sockaddr_in), check->tdata);
     if (status != PJ_SUCCESS) {
@@ -1399,10 +1418,9 @@ static pj_status_t on_stun_send_msg(pj_stun_session *sess,
 {
     stun_data *sd = (stun_data*) pj_stun_session_get_user_data(sess);
     pj_ice_sess *ice = sd->ice;
-    return (*sd->ice->cb.on_tx_pkt)(sd->ice, sd->lcand->comp_id, 
-				    GET_LCAND_ID(sd->lcand),
-				    pkt, pkt_size, 
-				    dst_addr, addr_len);
+    return (*ice->cb.on_tx_pkt)(ice, sd->comp_id, 
+				pkt, pkt_size, 
+				dst_addr, addr_len);
 }
 
 
@@ -1599,7 +1617,7 @@ static pj_status_t on_stun_rx_request(pj_stun_session *sess,
     pj_stun_priority_attr *ap;
     pj_stun_use_candidate_attr *uc;
     pj_ice_sess_comp *comp;
-    pj_ice_sess_cand *lcand;
+    pj_ice_sess_cand *lcand = NULL;
     pj_ice_sess_cand *rcand;
     unsigned i;
     pj_stun_tx_data *tdata;
@@ -1624,8 +1642,7 @@ static pj_status_t on_stun_rx_request(pj_stun_session *sess,
 
     sd = (stun_data*) pj_stun_session_get_user_data(sess);
     ice = sd->ice;
-    lcand = sd->lcand;
-    comp = find_comp(ice, lcand->comp_id);
+    comp = sd->comp;
 
     pj_mutex_lock(ice->mutex);
 
@@ -1682,7 +1699,7 @@ static pj_status_t on_stun_rx_request(pj_stun_session *sess,
      */
     if (i == ice->rcand_cnt) {
 	rcand = &ice->rcand[ice->rcand_cnt++];
-	rcand->comp_id = lcand->comp_id;
+	rcand->comp_id = sd->comp_id;
 	rcand->type = PJ_ICE_CAND_TYPE_PRFLX;
 	rcand->prio = ap->value;
 	pj_memcpy(&rcand->addr, src_addr, src_addr_len);
@@ -1703,6 +1720,36 @@ static pj_status_t on_stun_rx_request(pj_stun_session *sess,
 	rcand = &ice->rcand[i];
     }
 
+#if 0
+    /* Find again the local candidate by matching the base address
+     * with the local candidates in the checklist. Checks may have
+     * been pruned before, so it's possible that if we use the lcand
+     * as it is, we wouldn't be able to find the check in the checklist
+     * and we will end up creating a new check unnecessarily.
+     */
+    for (i=0; i<ice->clist.count; ++i) {
+	pj_ice_sess_check *c = &ice->clist.checks[i];
+	if (/*c->lcand == lcand ||*/
+	    sockaddr_cmp(&c->lcand->base_addr, &lcand->base_addr)==0)
+	{
+	    lcand = c->lcand;
+	    break;
+	}
+    }
+#else
+    /* Just get candidate with the highest priority for the specified 
+     * component ID in the checklist.
+     */
+    for (i=0; i<ice->clist.count; ++i) {
+	pj_ice_sess_check *c = &ice->clist.checks[i];
+	if (c->lcand->comp_id == sd->comp_id) {
+	    lcand = c->lcand;
+	    break;
+	}
+    }
+    pj_assert(lcand != NULL);
+#endif
+
     /* 
      * Create candidate pair for this request. 
      */
@@ -1822,14 +1869,13 @@ static pj_status_t on_stun_rx_indication(pj_stun_session *sess,
 }
 
 
-PJ_DEF(pj_status_t) pj_ice_sess_send_data( pj_ice_sess *ice,
-				      unsigned comp_id,
-				      const void *data,
-				      pj_size_t data_len)
+PJ_DEF(pj_status_t) pj_ice_sess_send_data(pj_ice_sess *ice,
+					  unsigned comp_id,
+					  const void *data,
+					  pj_size_t data_len)
 {
     pj_status_t status = PJ_SUCCESS;
     pj_ice_sess_comp *comp;
-    unsigned cand_id;
 
     PJ_ASSERT_RETURN(ice && comp_id && comp_id <= ice->comp_cnt, PJ_EINVAL);
     
@@ -1846,8 +1892,7 @@ PJ_DEF(pj_status_t) pj_ice_sess_send_data( pj_ice_sess *ice,
 	goto on_return;
     }
 
-    cand_id = GET_LCAND_ID(comp->valid_check->lcand);
-    status = (*ice->cb.on_tx_pkt)(ice, comp_id, cand_id, data, data_len, 
+    status = (*ice->cb.on_tx_pkt)(ice, comp_id, data, data_len, 
 				  &comp->valid_check->rcand->addr, 
 				  sizeof(pj_sockaddr_in));
 
@@ -1857,17 +1902,15 @@ on_return:
 }
 
 
-PJ_DEF(pj_status_t) pj_ice_sess_on_rx_pkt( pj_ice_sess *ice,
-				      unsigned comp_id,
-				      unsigned cand_id,
-				      void *pkt,
-				      pj_size_t pkt_size,
-				      const pj_sockaddr_t *src_addr,
-				      int src_addr_len)
+PJ_DEF(pj_status_t) pj_ice_sess_on_rx_pkt(pj_ice_sess *ice,
+					  unsigned comp_id,
+					  void *pkt,
+					  pj_size_t pkt_size,
+					  const pj_sockaddr_t *src_addr,
+					  int src_addr_len)
 {
     pj_status_t status = PJ_SUCCESS;
     pj_ice_sess_comp *comp;
-    pj_ice_sess_cand *lcand;
     pj_status_t stun_status;
 
     PJ_ASSERT_RETURN(ice, PJ_EINVAL);
@@ -1880,11 +1923,9 @@ PJ_DEF(pj_status_t) pj_ice_sess_on_rx_pkt( pj_ice_sess *ice,
 	goto on_return;
     }
 
-    lcand = &ice->lcand[cand_id];
-
     stun_status = pj_stun_msg_check(pkt, pkt_size, PJ_STUN_IS_DATAGRAM);
     if (stun_status == PJ_SUCCESS) {
-	status = pj_stun_session_on_rx_pkt(lcand->stun_sess, pkt, pkt_size,
+	status = pj_stun_session_on_rx_pkt(comp->stun_sess, pkt, pkt_size,
 					   PJ_STUN_IS_DATAGRAM,
 					   NULL, src_addr, src_addr_len);
     } else {
diff --git a/pjnath/src/pjnath/ice_strans.c b/pjnath/src/pjnath/ice_strans.c
index 082d310a..297e1f86 100644
--- a/pjnath/src/pjnath/ice_strans.c
+++ b/pjnath/src/pjnath/ice_strans.c
@@ -23,14 +23,22 @@
 #include <pj/ip_helper.h>
 #include <pj/log.h>
 #include <pj/pool.h>
+#include <pj/rand.h>
 #include <pj/string.h>
 
 
+#if 0
+#  define TRACE_PKT(expr)	    PJ_LOG(5,expr)
+#else
+#  define TRACE_PKT(expr)
+#endif
+
+
 
 /* ICE callbacks */
 static void	   on_ice_complete(pj_ice_sess *ice, pj_status_t status);
 static pj_status_t ice_tx_pkt(pj_ice_sess *ice, 
-			      unsigned comp_id, unsigned cand_id,
+			      unsigned comp_id,
 			      const void *pkt, pj_size_t size,
 			      const pj_sockaddr_t *dst_addr,
 			      unsigned dst_addr_len);
@@ -84,7 +92,7 @@ PJ_DECL(pj_status_t) pj_ice_strans_create(pj_stun_config *stun_cfg,
     PJ_ASSERT_RETURN(stun_cfg->ioqueue && stun_cfg->timer_heap, PJ_EINVAL);
 
     if (name == NULL)
-	name = "icest%p";
+	name = "icstr%p";
 
     pool = pj_pool_create(stun_cfg->pf, name, 4000, 4000, NULL);
     ice_st = PJ_POOL_ZALLOC_T(pool, pj_ice_strans);
@@ -242,6 +250,9 @@ static pj_status_t create_component(pj_ice_strans *ice_st,
     pj_ioqueue_callback ioqueue_cb;
     pj_ice_strans_comp *comp;
     int retry, addr_len;
+    struct {
+	pj_uint32_t a1, a2, a3;
+    } tsx_id;
     pj_status_t status;
 
     comp = PJ_POOL_ZALLOC_T(ice_st->pool, pj_ice_strans_comp);
@@ -251,6 +262,12 @@ static pj_status_t create_component(pj_ice_strans *ice_st,
     comp->sock = PJ_INVALID_SOCKET;
     comp->last_status = PJ_SUCCESS;
 
+    /* Create transaction ID for STUN keep alives */
+    tsx_id.a1 = 0;
+    tsx_id.a2 = comp_id;
+    tsx_id.a3 = (pj_uint32_t) ice_st;
+    pj_memcpy(comp->ka_tsx_id, &tsx_id, sizeof(comp->ka_tsx_id));
+
     /* Create socket */
     status = pj_sock_socket(PJ_AF_INET, PJ_SOCK_DGRAM, 0, &comp->sock);
     if (status != PJ_SUCCESS)
@@ -437,26 +454,31 @@ static void on_read_complete(pj_ioqueue_key_t *key,
 	 * So far we don't have good solution for this.
 	 * The process below is just a workaround.
 	 */
-	if (ice_st->ice) {
-	    PJ_TODO(DISTINGUISH_BETWEEN_LOCAL_AND_RELAY);
-	    status = pj_ice_sess_on_rx_pkt(ice_st->ice, comp->comp_id, 
-				      comp->cand_list[0].ice_cand_id,
-				      comp->pkt, bytes_read,
-				      &comp->src_addr, comp->src_addr_len);
-	} else if (comp->stun_sess) {
-	    status = pj_stun_msg_check(comp->pkt, bytes_read, 
-				       PJ_STUN_IS_DATAGRAM);
-	    if (status == PJ_SUCCESS) {
+	status = pj_stun_msg_check(comp->pkt, bytes_read, 
+				   PJ_STUN_IS_DATAGRAM);
+
+	if (status == PJ_SUCCESS) {
+	    if (ice_st->ice==NULL ||
+		pj_memcmp(comp->pkt+8, comp->ka_tsx_id, 12) == 0) 
+	    {
 		status = pj_stun_session_on_rx_pkt(comp->stun_sess, comp->pkt,
 						   bytes_read, 
 						   PJ_STUN_IS_DATAGRAM, NULL,
 						   &comp->src_addr, 
 						   comp->src_addr_len);
 	    } else {
-		(*ice_st->cb.on_rx_data)(ice_st, comp->comp_id, 
-					 comp->pkt, bytes_read, 
-					 &comp->src_addr, comp->src_addr_len);
-
+		PJ_TODO(DISTINGUISH_BETWEEN_LOCAL_AND_RELAY);
+
+		TRACE_PKT((comp->ice_st->obj_name, 
+			  "Component %d RX packet from %s:%d",
+			  comp->comp_id,
+			  pj_inet_ntoa(comp->src_addr.ipv4.sin_addr),
+			  (int)pj_ntohs(comp->src_addr.ipv4.sin_port)));
+
+		status = pj_ice_sess_on_rx_pkt(ice_st->ice, comp->comp_id, 
+					       comp->pkt, bytes_read,
+					       &comp->src_addr, 
+					       comp->src_addr_len);
 	    }
 	} else {
 	    (*ice_st->cb.on_rx_data)(ice_st, comp->comp_id, 
@@ -527,7 +549,8 @@ static void ka_timer_cb(pj_timer_heap_t *th, pj_timer_entry *te)
 
 	/* Create STUN binding request */
 	status = pj_stun_session_create_req(comp->stun_sess,
-					    PJ_STUN_BINDING_REQUEST, &tdata);
+					    PJ_STUN_BINDING_REQUEST, 
+					    comp->ka_tsx_id, &tdata);
 	if (status != PJ_SUCCESS)
 	    continue;
 
@@ -554,8 +577,9 @@ static void start_ka_timer(pj_ice_strans *ice_st)
     if (ice_st->ka_timer.id != PJ_FALSE)
 	return;
 
-    delay.sec = 20;
-    delay.msec = 0;
+    delay.sec = PJ_ICE_ST_KEEP_ALIVE_MIN;
+    delay.msec = pj_rand() % (PJ_ICE_ST_KEEP_ALIVE_MAX_RAND * 1000);
+    pj_time_val_normalize(&delay);
 
     ice_st->ka_timer.cb = &ka_timer_cb;
     ice_st->ka_timer.user_data = ice_st;
@@ -616,7 +640,9 @@ static pj_status_t get_stun_mapped_addr(pj_ice_strans *ice_st,
 
     /* Create STUN binding request */
     status = pj_stun_session_create_req(comp->stun_sess, 
-					PJ_STUN_BINDING_REQUEST, &tdata);
+					PJ_STUN_BINDING_REQUEST, 
+					comp->ka_tsx_id, 
+					&tdata);
     if (status != PJ_SUCCESS)
 	return status;
 
@@ -944,7 +970,7 @@ static void on_ice_complete(pj_ice_sess *ice, pj_status_t status)
  * Callback called by ICE session when it wants to send outgoing packet.
  */
 static pj_status_t ice_tx_pkt(pj_ice_sess *ice, 
-			      unsigned comp_id, unsigned cand_id,
+			      unsigned comp_id, 
 			      const void *pkt, pj_size_t size,
 			      const pj_sockaddr_t *dst_addr,
 			      unsigned dst_addr_len)
@@ -959,6 +985,12 @@ static pj_status_t ice_tx_pkt(pj_ice_sess *ice,
     PJ_ASSERT_RETURN(comp_id && comp_id <= ice_st->comp_cnt, PJ_EINVAL);
     comp = ice_st->comp[comp_id-1];
 
+    TRACE_PKT((comp->ice_st->obj_name, 
+	      "Component %d TX packet to %s:%d",
+	      comp_id,
+	      pj_inet_ntoa(((pj_sockaddr_in*)dst_addr)->sin_addr),
+	      (int)pj_ntohs(((pj_sockaddr_in*)dst_addr)->sin_port)));
+
     pkt_size = size;
     status = pj_ioqueue_sendto(comp->key, &comp->write_op, 
 			       pkt, &pkt_size, 0,
@@ -1026,6 +1058,10 @@ static void stun_on_request_complete(pj_stun_session *sess,
 
     if (cand == NULL) {
 	/* This is keep-alive */
+	if (status != PJ_SUCCESS) {
+	    ice_st_perror(comp->ice_st, "STUN keep-alive request failed",
+			  status);
+	}
 	return;
     }
 
diff --git a/pjnath/src/pjnath/stun_session.c b/pjnath/src/pjnath/stun_session.c
index 5f308fcd..db1339d7 100644
--- a/pjnath/src/pjnath/stun_session.c
+++ b/pjnath/src/pjnath/stun_session.c
@@ -49,17 +49,19 @@ struct pj_stun_session
 #define TDATA_POOL_INC		    1024
 
 
-static void tsx_on_complete(pj_stun_client_tsx *tsx,
-			    pj_status_t status, 
-			    const pj_stun_msg *response);
-static pj_status_t tsx_on_send_msg(pj_stun_client_tsx *tsx,
-				   const void *stun_pkt,
-				   pj_size_t pkt_size);
+static void stun_tsx_on_complete(pj_stun_client_tsx *tsx,
+				 pj_status_t status, 
+				 const pj_stun_msg *response);
+static pj_status_t stun_tsx_on_send_msg(pj_stun_client_tsx *tsx,
+					const void *stun_pkt,
+					pj_size_t pkt_size);
+static void stun_tsx_on_destroy(pj_stun_client_tsx *tsx);
 
 static pj_stun_tsx_cb tsx_cb = 
 {
-    &tsx_on_complete,
-    &tsx_on_send_msg
+    &stun_tsx_on_complete,
+    &stun_tsx_on_send_msg,
+    &stun_tsx_on_destroy
 };
 
 
@@ -120,6 +122,7 @@ static pj_status_t create_tdata(pj_stun_session *sess,
 
 static pj_status_t create_request_tdata(pj_stun_session *sess,
 					unsigned msg_type,
+					const pj_uint8_t tsx_id[12],
 					pj_stun_tx_data **p_tdata)
 {
     pj_status_t status;
@@ -131,7 +134,7 @@ static pj_status_t create_request_tdata(pj_stun_session *sess,
 
     /* Create STUN message */
     status = pj_stun_msg_create(tdata->pool, msg_type,  PJ_STUN_MAGIC, 
-				NULL, &tdata->msg);
+				tsx_id, &tdata->msg);
     if (status != PJ_SUCCESS) {
 	pj_pool_release(tdata->pool);
 	return status;
@@ -148,20 +151,34 @@ static pj_status_t create_request_tdata(pj_stun_session *sess,
     return PJ_SUCCESS;
 }
 
+
+static void stun_tsx_on_destroy(pj_stun_client_tsx *tsx)
+{
+    pj_stun_tx_data *tdata;
+
+    tdata = (pj_stun_tx_data*) pj_stun_client_tsx_get_data(tsx);
+    pj_stun_client_tsx_destroy(tsx);
+    pj_pool_release(tdata->pool);
+}
+
 static void destroy_tdata(pj_stun_tx_data *tdata)
 {
-    if (tdata->client_tsx) {
-	tsx_erase(tdata->sess, tdata);
-	pj_stun_client_tsx_destroy(tdata->client_tsx);
-	tdata->client_tsx = NULL;
-    }
     if (tdata->res_timer.id != PJ_FALSE) {
 	pj_timer_heap_cancel(tdata->sess->cfg->timer_heap, 
 			     &tdata->res_timer);
 	tdata->res_timer.id = PJ_FALSE;
 	pj_list_erase(tdata);
     }
-    pj_pool_release(tdata->pool);
+
+    if (tdata->client_tsx) {
+	pj_time_val delay = {2, 0};
+	tsx_erase(tdata->sess, tdata);
+	pj_stun_client_tsx_schedule_destroy(tdata->client_tsx, &delay);
+	tdata->client_tsx = NULL;
+
+    } else {
+	pj_pool_release(tdata->pool);
+    }
 }
 
 /*
@@ -306,9 +323,9 @@ static pj_status_t apply_msg_options(pj_stun_session *sess,
 }
 
 
-static void tsx_on_complete(pj_stun_client_tsx *tsx,
-			    pj_status_t status, 
-			    const pj_stun_msg *response)
+static void stun_tsx_on_complete(pj_stun_client_tsx *tsx,
+				 pj_status_t status, 
+				 const pj_stun_msg *response)
 {
     pj_stun_tx_data *tdata;
 
@@ -320,9 +337,9 @@ static void tsx_on_complete(pj_stun_client_tsx *tsx,
     }
 }
 
-static pj_status_t tsx_on_send_msg(pj_stun_client_tsx *tsx,
-				   const void *stun_pkt,
-				   pj_size_t pkt_size)
+static pj_status_t stun_tsx_on_send_msg(pj_stun_client_tsx *tsx,
+					const void *stun_pkt,
+					pj_size_t pkt_size)
 {
     pj_stun_tx_data *tdata;
 
@@ -441,6 +458,7 @@ PJ_DEF(void) pj_stun_session_set_credential(pj_stun_session *sess,
 
 PJ_DEF(pj_status_t) pj_stun_session_create_req(pj_stun_session *sess,
 					       int method,
+					       const pj_uint8_t tsx_id[12],
 					       pj_stun_tx_data **p_tdata)
 {
     pj_stun_tx_data *tdata = NULL;
@@ -448,7 +466,7 @@ PJ_DEF(pj_status_t) pj_stun_session_create_req(pj_stun_session *sess,
 
     PJ_ASSERT_RETURN(sess && p_tdata, PJ_EINVAL);
 
-    status = create_request_tdata(sess, method, &tdata);
+    status = create_request_tdata(sess, method, tsx_id, &tdata);
     if (status != PJ_SUCCESS)
 	return status;
 
@@ -765,7 +783,7 @@ static pj_status_t on_incoming_response(pj_stun_session *sess,
     /* Lookup pending client transaction */
     tdata = tsx_lookup(sess, msg);
     if (tdata == NULL) {
-	PJ_LOG(5,(SNAME(sess), 
+	PJ_LOG(4,(SNAME(sess), 
 		  "Transaction not found, response silently discarded"));
 	return PJ_SUCCESS;
     }
diff --git a/pjnath/src/pjnath/stun_transaction.c b/pjnath/src/pjnath/stun_transaction.c
index 5d6f80f6..9c5bc11a 100644
--- a/pjnath/src/pjnath/stun_transaction.c
+++ b/pjnath/src/pjnath/stun_transaction.c
@@ -36,12 +36,14 @@ struct pj_stun_client_tsx
     void		*user_data;
 
     pj_bool_t		 complete;
-    \
+
     pj_bool_t		 require_retransmit;
-    pj_timer_entry	 timer;
+    pj_timer_entry	 retransmit_timer;
     unsigned		 transmit_count;
     pj_time_val		 retransmit_time;
 
+    pj_timer_entry	 destroy_timer;
+
     void		*last_pkt;
     unsigned		 last_pkt_size;
 };
@@ -49,6 +51,8 @@ struct pj_stun_client_tsx
 
 static void retransmit_timer_callback(pj_timer_heap_t *timer_heap, 
 				      pj_timer_entry *timer);
+static void destroy_timer_callback(pj_timer_heap_t *timer_heap, 
+				   pj_timer_entry *timer);
 
 #define stun_perror(tsx,msg,rc) pjnath_perror(tsx->obj_name, msg, rc)
 
@@ -69,8 +73,11 @@ PJ_DEF(pj_status_t) pj_stun_client_tsx_create(pj_stun_config *cfg,
     tsx->cfg = cfg;
     pj_memcpy(&tsx->cb, cb, sizeof(*cb));
 
-    tsx->timer.cb = &retransmit_timer_callback;
-    tsx->timer.user_data = tsx;
+    tsx->retransmit_timer.cb = &retransmit_timer_callback;
+    tsx->retransmit_timer.user_data = tsx;
+
+    tsx->destroy_timer.cb = &destroy_timer_callback;
+    tsx->destroy_timer.user_data = tsx;
 
     pj_ansi_snprintf(tsx->obj_name, sizeof(tsx->obj_name), "stuntsx%p", tsx);
 
@@ -81,17 +88,55 @@ PJ_DEF(pj_status_t) pj_stun_client_tsx_create(pj_stun_config *cfg,
 }
 
 
+PJ_DEF(pj_status_t) 
+pj_stun_client_tsx_schedule_destroy(pj_stun_client_tsx *tsx,
+				    const pj_time_val *delay)
+{
+    pj_status_t status;
+
+    PJ_ASSERT_RETURN(tsx && delay, PJ_EINVAL);
+    PJ_ASSERT_RETURN(tsx->cb.on_destroy, PJ_EINVAL);
+
+    /* Cancel previously registered timer */
+    if (tsx->destroy_timer.id != 0) {
+	pj_timer_heap_cancel(tsx->cfg->timer_heap, &tsx->destroy_timer);
+	tsx->destroy_timer.id = 0;
+    }
+
+    /* Stop retransmission, just in case */
+    if (tsx->retransmit_timer.id != 0) {
+	pj_timer_heap_cancel(tsx->cfg->timer_heap, &tsx->retransmit_timer);
+	tsx->retransmit_timer.id = 0;
+    }
+
+    status = pj_timer_heap_schedule(tsx->cfg->timer_heap,
+				    &tsx->destroy_timer, delay);
+    if (status != PJ_SUCCESS)
+	return status;
+
+    tsx->destroy_timer.id = TIMER_ACTIVE;
+
+    return PJ_SUCCESS;
+}
+
+
 /*
- * .
+ * Destroy transaction immediately.
  */
 PJ_DEF(pj_status_t) pj_stun_client_tsx_destroy(pj_stun_client_tsx *tsx)
 {
     PJ_ASSERT_RETURN(tsx, PJ_EINVAL);
 
-    if (tsx->timer.id != 0) {
-	pj_timer_heap_cancel(tsx->cfg->timer_heap, &tsx->timer);
-	tsx->timer.id = 0;
+    if (tsx->retransmit_timer.id != 0) {
+	pj_timer_heap_cancel(tsx->cfg->timer_heap, &tsx->retransmit_timer);
+	tsx->retransmit_timer.id = 0;
+    }
+    if (tsx->destroy_timer.id != 0) {
+	pj_timer_heap_cancel(tsx->cfg->timer_heap, &tsx->destroy_timer);
+	tsx->destroy_timer.id = 0;
     }
+
+    PJ_LOG(5,(tsx->obj_name, "STUN client transaction destroyed"));
     return PJ_SUCCESS;
 }
 
@@ -135,7 +180,7 @@ static pj_status_t tsx_transmit_msg(pj_stun_client_tsx *tsx)
 {
     pj_status_t status;
 
-    PJ_ASSERT_RETURN(tsx->timer.id == 0, PJ_EBUSY);
+    PJ_ASSERT_RETURN(tsx->retransmit_timer.id == 0, PJ_EBUSY);
 
     if (tsx->require_retransmit) {
 	/* Calculate retransmit/timeout delay */
@@ -160,22 +205,24 @@ static pj_status_t tsx_transmit_msg(pj_stun_client_tsx *tsx)
 	 * cancel it (as opposed to when schedule_timer() failed we cannot
 	 * cancel transmission).
 	 */;
-	status = pj_timer_heap_schedule(tsx->cfg->timer_heap, &tsx->timer,
+	status = pj_timer_heap_schedule(tsx->cfg->timer_heap, 
+					&tsx->retransmit_timer,
 					&tsx->retransmit_time);
 	if (status != PJ_SUCCESS) {
-	    tsx->timer.id = 0;
+	    tsx->retransmit_timer.id = 0;
 	    return status;
 	}
-	tsx->timer.id = TIMER_ACTIVE;
+	tsx->retransmit_timer.id = TIMER_ACTIVE;
     }
 
 
     /* Send message */
     status = tsx->cb.on_send_msg(tsx, tsx->last_pkt, tsx->last_pkt_size);
     if (status != PJ_SUCCESS) {
-	if (tsx->timer.id != 0) {
-	    pj_timer_heap_cancel(tsx->cfg->timer_heap, &tsx->timer);
-	    tsx->timer.id = 0;
+	if (tsx->retransmit_timer.id != 0) {
+	    pj_timer_heap_cancel(tsx->cfg->timer_heap, 
+				 &tsx->retransmit_timer);
+	    tsx->retransmit_timer.id = 0;
 	}
 	stun_perror(tsx, "STUN error sending message", status);
 	return status;
@@ -198,7 +245,7 @@ PJ_DEF(pj_status_t) pj_stun_client_tsx_send_msg(pj_stun_client_tsx *tsx,
 						unsigned pkt_len)
 {
     PJ_ASSERT_RETURN(tsx && pkt && pkt_len, PJ_EINVAL);
-    PJ_ASSERT_RETURN(tsx->timer.id == 0, PJ_EBUSY);
+    PJ_ASSERT_RETURN(tsx->retransmit_timer.id == 0, PJ_EBUSY);
 
     /* Encode message */
     tsx->last_pkt = pkt;
@@ -223,27 +270,44 @@ static void retransmit_timer_callback(pj_timer_heap_t *timer_heap,
 
     if (tsx->transmit_count >= PJ_STUN_MAX_RETRANSMIT_COUNT) {
 	/* Retransmission count exceeded. Transaction has failed */
-	tsx->timer.id = 0;
+	tsx->retransmit_timer.id = 0;
 	PJ_LOG(4,(tsx->obj_name, "STUN timeout waiting for response"));
-	tsx->complete = PJ_TRUE;
-	if (tsx->cb.on_complete) {
-	    tsx->cb.on_complete(tsx, PJNATH_ESTUNTIMEDOUT, NULL);
+	if (!tsx->complete) {
+	    tsx->complete = PJ_TRUE;
+	    if (tsx->cb.on_complete) {
+		tsx->cb.on_complete(tsx, PJNATH_ESTUNTIMEDOUT, NULL);
+	    }
 	}
 	return;
     }
 
-    tsx->timer.id = 0;
+    tsx->retransmit_timer.id = 0;
     status = tsx_transmit_msg(tsx);
     if (status != PJ_SUCCESS) {
-	tsx->timer.id = 0;
-	tsx->complete = PJ_TRUE;
-	if (tsx->cb.on_complete) {
-	    tsx->cb.on_complete(tsx, status, NULL);
+	tsx->retransmit_timer.id = 0;
+	if (!tsx->complete) {
+	    tsx->complete = PJ_TRUE;
+	    if (tsx->cb.on_complete) {
+		tsx->cb.on_complete(tsx, status, NULL);
+	    }
 	}
     }
 }
 
 
+/* Timer callback to destroy transaction */
+static void destroy_timer_callback(pj_timer_heap_t *timer_heap, 
+				   pj_timer_entry *timer)
+{
+    pj_stun_client_tsx *tsx = (pj_stun_client_tsx *) timer->user_data;
+
+    PJ_UNUSED_ARG(timer_heap);
+
+    tsx->destroy_timer.id = PJ_FALSE;
+    tsx->cb.on_destroy(tsx);
+    /* Don't access transaction after this */
+}
+
 
 /*
  * Notify the STUN transaction about the arrival of STUN response.
@@ -267,9 +331,9 @@ PJ_DEF(pj_status_t) pj_stun_client_tsx_on_rx_msg(pj_stun_client_tsx *tsx,
     /* We have a response with matching transaction ID. 
      * We can cancel retransmit timer now.
      */
-    if (tsx->timer.id) {
-	pj_timer_heap_cancel(tsx->cfg->timer_heap, &tsx->timer);
-	tsx->timer.id = 0;
+    if (tsx->retransmit_timer.id) {
+	pj_timer_heap_cancel(tsx->cfg->timer_heap, &tsx->retransmit_timer);
+	tsx->retransmit_timer.id = 0;
     }
 
     /* Find STUN error code attribute */
@@ -296,9 +360,11 @@ PJ_DEF(pj_status_t) pj_stun_client_tsx_on_rx_msg(pj_stun_client_tsx *tsx,
     }
 
     /* Call callback */
-    tsx->complete = PJ_TRUE;
-    if (tsx->cb.on_complete) {
-	tsx->cb.on_complete(tsx, status, msg);
+    if (!tsx->complete) {
+	tsx->complete = PJ_TRUE;
+	if (tsx->cb.on_complete) {
+	    tsx->cb.on_complete(tsx, status, msg);
+	}
     }
 
     return PJ_SUCCESS;