Fixed ticket #999:

Several bug fixes to the TURN client library and icedemo sample application:

 1. ICE stream transport reports ICE initialization/candidate gathering stage as successful even when TURN client TCP connection has failed.
 2. Bad ChannelData framing when TCP is used. PJNATH did not properly add padding to the TURN ChannelData packet if TCP is used and the data is not aligned to four bytes boundary. Similarly incoming ChannelData with padding (over TCP) may not be handled correctly.
 3. Incoming data over TCP may be delayed. PJNATH only processed one frame (be it request, indication, or ChannelData) on an incoming stream, so if the stream contains more than one frames, the processing of subsequent frames will be delayed until more stream is received on the TCP transport.
 4. The icedemo sample application overwrites the incoming packet buffer with NULL character ('\0') before printing the message to console. If there is another packet after current packet (as often happens when TCP is used), the subsequent packet will get corrupted. 

The combinations of bugs above may cause PJNATH to return "Invalid STUN message length (PJNATH_EINSTUNMSGLEN)" error when processing incoming TURN ChannelData message over TCP.

And a small enhancement:

  1. Add logging to file option to icedemo sample. 

Thanks Sarun Nandakumar for the report.




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

5 files changed, 139 insertions, 24 deletions

diff --git a/pjnath/include/pjnath/ice_strans.h b/pjnath/include/pjnath/ice_strans.h
index 43a837da..158c303c 100644
--- a/pjnath/include/pjnath/ice_strans.h
+++ b/pjnath/include/pjnath/ice_strans.h
@@ -622,6 +622,17 @@ PJ_DECL(pj_status_t) pj_ice_strans_get_ufrag_pwd(pj_ice_strans *ice_st,
 
 
 /**
+ * Get the number of local candidates for the specified component ID.
+ *
+ * @param ice_st	The ICE stream transport.
+ * @param comp_id	Component ID.
+ *
+ * @return		The number of candidates.
+ */
+PJ_DECL(unsigned) pj_ice_strans_get_cands_count(pj_ice_strans *ice_st,
+					        unsigned comp_id);
+
+/**
  * Enumerate the local candidates for the specified component.
  *
  * @param ice_st	The ICE stream transport.
diff --git a/pjnath/include/pjnath/turn_session.h b/pjnath/include/pjnath/turn_session.h
index 64f12787..39e4cbf4 100644
--- a/pjnath/include/pjnath/turn_session.h
+++ b/pjnath/include/pjnath/turn_session.h
@@ -455,11 +455,19 @@ PJ_DECL(pj_status_t) pj_turn_session_shutdown(pj_turn_session *sess);
  * be notified about the client destruction.
  *
  * @param sess		The TURN client session.
+ * @param last_err	Optional error code to be set to the session,
+ *			which would be returned back in the \a info
+ *			parameter of #pj_turn_session_get_info(). If
+ *			this argument value is PJ_SUCCESS, the error
+ *			code will not be set. If the session already
+ *			has an error code set, this function will not
+ *			overwrite that error code either.
  *
  * @return		PJ_SUCCESS if the operation has been successful,
  *			or the appropriate error code on failure.
  */
-PJ_DECL(pj_status_t) pj_turn_session_destroy(pj_turn_session *sess);
+PJ_DECL(pj_status_t) pj_turn_session_destroy(pj_turn_session *sess,
+					     pj_status_t last_err);
 
 
 /**
diff --git a/pjnath/src/pjnath/ice_strans.c b/pjnath/src/pjnath/ice_strans.c
index d702c656..b5608cb0 100644
--- a/pjnath/src/pjnath/ice_strans.c
+++ b/pjnath/src/pjnath/ice_strans.c
@@ -912,6 +912,27 @@ PJ_DEF(pj_status_t) pj_ice_strans_get_ufrag_pwd( pj_ice_strans *ice_st,
 }
 
 /*
+ * Get number of candidates
+ */
+PJ_DEF(unsigned) pj_ice_strans_get_cands_count(pj_ice_strans *ice_st,
+					       unsigned comp_id)
+{
+    unsigned i, cnt;
+
+    PJ_ASSERT_RETURN(ice_st && ice_st->ice && comp_id && 
+		     comp_id <= ice_st->comp_cnt, 0);
+
+    cnt = 0;
+    for (i=0; i<ice_st->ice->lcand_cnt; ++i) {
+	if (ice_st->ice->lcand[i].comp_id != comp_id)
+	    continue;
+	++cnt;
+    }
+
+    return cnt;
+}
+
+/*
  * Enum candidates
  */
 PJ_DEF(pj_status_t) pj_ice_strans_enum_cands(pj_ice_strans *ice_st,
diff --git a/pjnath/src/pjnath/turn_session.c b/pjnath/src/pjnath/turn_session.c
index f3a33ea6..f0833b3f 100644
--- a/pjnath/src/pjnath/turn_session.c
+++ b/pjnath/src/pjnath/turn_session.c
@@ -461,10 +461,13 @@ PJ_DEF(pj_status_t) pj_turn_session_shutdown(pj_turn_session *sess)
 /**
  * Forcefully destroy the TURN session.
  */
-PJ_DEF(pj_status_t) pj_turn_session_destroy( pj_turn_session *sess)
+PJ_DEF(pj_status_t) pj_turn_session_destroy( pj_turn_session *sess,
+					     pj_status_t last_err)
 {
     PJ_ASSERT_RETURN(sess, PJ_EINVAL);
 
+    if (last_err != PJ_SUCCESS && sess->last_status == PJ_SUCCESS)
+	sess->last_status = last_err;
     set_state(sess, PJ_TURN_STATE_DEALLOCATED);
     sess_shutdown(sess, PJ_SUCCESS);
     return PJ_SUCCESS;
@@ -959,12 +962,16 @@ PJ_DEF(pj_status_t) pj_turn_session_sendto( pj_turn_session *sess,
     ch = lookup_ch_by_addr(sess, addr, pj_sockaddr_get_len(addr), 
 			   PJ_FALSE, PJ_FALSE);
     if (ch && ch->num != PJ_TURN_INVALID_CHANNEL && ch->bound) {
+	unsigned total_len;
+
 	/* Peer is assigned a channel number, we can use ChannelData */
 	pj_turn_channel_data *cd = (pj_turn_channel_data*)sess->tx_pkt;
 	
 	pj_assert(sizeof(*cd)==4);
 
-	if (pkt_len > sizeof(sess->tx_pkt)-sizeof(*cd)) {
+	/* Calculate total length, including paddings */
+	total_len = (pkt_len + sizeof(*cd) + 3) & (~3);
+	if (total_len > sizeof(sess->tx_pkt)) {
 	    status = PJ_ETOOBIG;
 	    goto on_return;
 	}
@@ -975,7 +982,7 @@ PJ_DEF(pj_status_t) pj_turn_session_sendto( pj_turn_session *sess,
 
 	pj_assert(sess->srv_addr != NULL);
 
-	status = sess->cb.on_send_pkt(sess, sess->tx_pkt, pkt_len+sizeof(*cd),
+	status = sess->cb.on_send_pkt(sess, sess->tx_pkt, total_len,
 				      sess->srv_addr,
 				      pj_sockaddr_get_len(sess->srv_addr));
 
@@ -1156,7 +1163,8 @@ PJ_DEF(pj_status_t) pj_turn_session_on_rx_pkt(pj_turn_session *sess,
 	    goto on_return;
 	} else {
 	    if (parsed_len) {
-		*parsed_len = cd.length + sizeof(cd);
+		/* Apply padding too */
+		*parsed_len = ((cd.length + 3) & (~3)) + sizeof(cd);
 	    }
 	}
 
diff --git a/pjnath/src/pjnath/turn_sock.c b/pjnath/src/pjnath/turn_sock.c
index 287b0299..e2823ff3 100644
--- a/pjnath/src/pjnath/turn_sock.c
+++ b/pjnath/src/pjnath/turn_sock.c
@@ -273,14 +273,7 @@ static void timer_cb(pj_timer_heap_t *th, pj_timer_entry *e)
 static void show_err(pj_turn_sock *turn_sock, const char *title,
 		     pj_status_t status)
 {
-    char errmsg[PJ_ERR_MSG_SIZE];
-
-    if (status != PJ_SUCCESS) {
-	pj_strerror(status, errmsg, sizeof(errmsg));
-	PJ_LOG(4,(turn_sock->obj_name, "%s: %s", title, errmsg));
-    } else {
-	PJ_LOG(4,(turn_sock->obj_name, "%s", title, errmsg));
-    }
+    PJ_PERROR(4,(turn_sock->obj_name, status, title));
 }
 
 /* On error, terminate session */
@@ -288,8 +281,9 @@ static void sess_fail(pj_turn_sock *turn_sock, const char *title,
 		      pj_status_t status)
 {
     show_err(turn_sock, title, status);
-    if (turn_sock->sess)
-	pj_turn_session_destroy(turn_sock->sess);
+    if (turn_sock->sess) {
+	pj_turn_session_destroy(turn_sock->sess, status);
+    }
 }
 
 /*
@@ -494,6 +488,49 @@ static pj_bool_t on_connect_complete(pj_activesock_t *asock,
     return PJ_TRUE;
 }
 
+static pj_uint16_t GETVAL16H(const pj_uint8_t *buf, unsigned pos)
+{
+    return (pj_uint16_t) ((buf[pos + 0] << 8) | \
+			  (buf[pos + 1] << 0));
+}
+
+/* Quick check to determine if there is enough packet to process in the
+ * incoming buffer. Return the packet length, or zero if there's no packet.
+ */
+static unsigned has_packet(pj_turn_sock *turn_sock, const void *buf, pj_size_t bufsize)
+{
+    pj_bool_t is_stun;
+
+    if (turn_sock->conn_type == PJ_TURN_TP_UDP)
+	return bufsize;
+
+    /* Quickly check if this is STUN message, by checking the first two bits and
+     * size field which must be multiple of 4 bytes
+     */
+    is_stun = ((((pj_uint8_t*)buf)[0] & 0xC0) == 0) &&
+	      ((GETVAL16H((const pj_uint8_t*)buf, 2) & 0x03)==0);
+
+    if (is_stun) {
+	pj_size_t msg_len = GETVAL16H((const pj_uint8_t*)buf, 2);
+	return (msg_len+20 <= bufsize) ? msg_len+20 : 0;
+    } else {
+	/* This must be ChannelData. */
+	pj_turn_channel_data cd;
+
+	if (bufsize < 4)
+	    return 0;
+
+	/* Decode ChannelData packet */
+	pj_memcpy(&cd, buf, sizeof(pj_turn_channel_data));
+	cd.length = pj_ntohs(cd.length);
+
+	if (bufsize >= cd.length+sizeof(cd)) 
+	    return (cd.length+sizeof(cd)+3) & (~3);
+	else
+	    return 0;
+    }
+}
+
 /*
  * Notification from ioqueue when incoming UDP packet is received.
  */
@@ -504,21 +541,51 @@ static pj_bool_t on_data_read(pj_activesock_t *asock,
 			      pj_size_t *remainder)
 {
     pj_turn_sock *turn_sock;
-    pj_size_t parsed_len;
     pj_bool_t ret = PJ_TRUE;
 
     turn_sock = (pj_turn_sock*) pj_activesock_get_user_data(asock);
     pj_lock_acquire(turn_sock->lock);
 
     if (status == PJ_SUCCESS && turn_sock->sess) {
-	/* Report incoming packet to TURN session */
-	parsed_len = (unsigned)size;
-	pj_turn_session_on_rx_pkt(turn_sock->sess, data,  size, &parsed_len);
-	if (parsed_len < (unsigned)size) {
-	    *remainder = size - parsed_len;
-	    pj_memmove(data, ((char*)data)+parsed_len, *remainder);
-	} else {
-	    *remainder = 0;
+	/* Report incoming packet to TURN session, repeat while we have
+	 * "packet" in the buffer (required for stream-oriented transports)
+	 */
+	unsigned pkt_len;
+
+	//PJ_LOG(5,(turn_sock->pool->obj_name, 
+	//	  "Incoming data, %lu bytes total buffer", size));
+
+	while ((pkt_len=has_packet(turn_sock, data, size)) != 0) {
+	    pj_size_t parsed_len;
+	    //const pj_uint8_t *pkt = (const pj_uint8_t*)data;
+
+	    //PJ_LOG(5,(turn_sock->pool->obj_name, 
+	    //	      "Packet start: %02X %02X %02X %02X", 
+	    //	      pkt[0], pkt[1], pkt[2], pkt[3]));
+
+	    //PJ_LOG(5,(turn_sock->pool->obj_name, 
+	    //	      "Processing %lu bytes packet of %lu bytes total buffer",
+	    //	      pkt_len, size));
+
+	    parsed_len = (unsigned)size;
+	    pj_turn_session_on_rx_pkt(turn_sock->sess, data,  size, &parsed_len);
+
+	    /* parsed_len may be zero if we have parsing error, so use our
+	     * previous calculation to exhaust the bad packet.
+	     */
+	    if (parsed_len == 0)
+		parsed_len = pkt_len;
+
+	    if (parsed_len < (unsigned)size) {
+		*remainder = size - parsed_len;
+		pj_memmove(data, ((char*)data)+parsed_len, *remainder);
+	    } else {
+		*remainder = 0;
+	    }
+	    size = *remainder;
+
+	    //PJ_LOG(5,(turn_sock->pool->obj_name, 
+	    //	      "Buffer size now %lu bytes", size));
 	}
     } else if (status != PJ_SUCCESS && 
 	       turn_sock->conn_type != PJ_TURN_TP_UDP)