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: https://svn.pjsip.org/repos/pjproject/trunk@3028 74dad513-b988-da41-8d7b-12977e46ad98
diff --git a/pjnath/include/pjnath/ice_strans.h b/pjnath/include/pjnath/ice_strans.h
index 43a837d..158c303 100644
--- a/pjnath/include/pjnath/ice_strans.h
+++ b/pjnath/include/pjnath/ice_strans.h
@@ -622,6 +622,17 @@
/**
+ * 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 64f1278..39e4cbf 100644
--- a/pjnath/include/pjnath/turn_session.h
+++ b/pjnath/include/pjnath/turn_session.h
@@ -455,11 +455,19 @@
* 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 d702c65..b5608cb 100644
--- a/pjnath/src/pjnath/ice_strans.c
+++ b/pjnath/src/pjnath/ice_strans.c
@@ -912,6 +912,27 @@
}
/*
+ * 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 f3a33ea..f0833b3 100644
--- a/pjnath/src/pjnath/turn_session.c
+++ b/pjnath/src/pjnath/turn_session.c
@@ -461,10 +461,13 @@
/**
* 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 @@
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_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 @@
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 287b029..e2823ff 100644
--- a/pjnath/src/pjnath/turn_sock.c
+++ b/pjnath/src/pjnath/turn_sock.c
@@ -273,14 +273,7 @@
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 @@
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 @@
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 @@
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)
diff --git a/pjsip-apps/src/samples/debug.c b/pjsip-apps/src/samples/debug.c
index b8b624d..5417a79 100644
--- a/pjsip-apps/src/samples/debug.c
+++ b/pjsip-apps/src/samples/debug.c
@@ -28,5 +28,5 @@
* E.g.:
* #include "playfile.c"
*/
-#include "jbsim.c"
+#include "icedemo.c"
diff --git a/pjsip-apps/src/samples/icedemo.c b/pjsip-apps/src/samples/icedemo.c
index f3f7c6c..1f2a020 100644
--- a/pjsip-apps/src/samples/icedemo.c
+++ b/pjsip-apps/src/samples/icedemo.c
@@ -47,6 +47,7 @@
pj_str_t turn_username;
pj_str_t turn_password;
pj_bool_t turn_fingerprint;
+ const char *log_file;
} opt;
/* Our global variables */
@@ -56,6 +57,7 @@
pj_bool_t thread_quit_flag;
pj_ice_strans_cfg ice_cfg;
pj_ice_strans *icest;
+ FILE *log_fhnd;
/* Variables to store parsed remote ICE info */
struct rem_info
@@ -109,6 +111,12 @@
pj_caching_pool_destroy(&icedemo.cp);
pj_shutdown();
+
+ if (icedemo.log_fhnd) {
+ fclose(icedemo.log_fhnd);
+ icedemo.log_fhnd = NULL;
+ }
+
exit(status != PJ_SUCCESS);
}
@@ -216,11 +224,13 @@
PJ_UNUSED_ARG(src_addr_len);
PJ_UNUSED_ARG(pkt);
- ((char*)pkt)[size] = '\0';
+ // Don't do this! It will ruin the packet buffer in case TCP is used!
+ //((char*)pkt)[size] = '\0';
- PJ_LOG(3,(THIS_FILE, "Component %d: received %d bytes data from %s: \"%s\"",
+ PJ_LOG(3,(THIS_FILE, "Component %d: received %d bytes data from %s: \"%.*s\"",
comp_id, size,
pj_sockaddr_print(src_addr, ipstr, sizeof(ipstr), 3),
+ (unsigned)size,
(char*)pkt));
}
@@ -236,8 +246,6 @@
(op==PJ_ICE_STRANS_OP_INIT? "initialization" :
(op==PJ_ICE_STRANS_OP_NEGOTIATION ? "negotiation" : "unknown_op"));
- PJ_UNUSED_ARG(ice_st);
-
if (status == PJ_SUCCESS) {
PJ_LOG(3,(THIS_FILE, "ICE %s successful", opname));
} else {
@@ -245,9 +253,18 @@
pj_strerror(status, errmsg, sizeof(errmsg));
PJ_LOG(1,(THIS_FILE, "ICE %s failed: %s", opname, errmsg));
+ pj_ice_strans_destroy(ice_st);
+ icedemo.icest = NULL;
}
}
+/* log callback to write to file */
+static void log_func(int level, const char *data, int len)
+{
+ if (icedemo.log_fhnd)
+ fwrite(data, len, 1, icedemo.log_fhnd);
+ pj_log_write(level, data, len);
+}
/*
* This is the main application initialization function. It is called
@@ -258,6 +275,11 @@
{
pj_status_t status;
+ if (icedemo.opt.log_file) {
+ icedemo.log_fhnd = fopen(icedemo.opt.log_file, "a");
+ pj_log_set_log_func(&log_func);
+ }
+
/* Initialize the libraries before anything else */
CHECK( pj_init() );
CHECK( pjlib_util_init() );
@@ -1147,6 +1169,7 @@
puts(" resolution");
puts(" --max-host, -H N Set max number of host candidates to N");
puts(" --regular, -R Use regular nomination (default aggressive)");
+ puts(" --log-file, -L FILE Save output to log FILE");
puts(" --help, -h Display this screen.");
puts("");
puts("STUN related options:");
@@ -1182,7 +1205,8 @@
{ "turn-username", 1, 0, 'u'},
{ "turn-password", 1, 0, 'p'},
{ "turn-fingerprint", 0, 0, 'F'},
- { "regular", 0, 0, 'R'}
+ { "regular", 0, 0, 'R'},
+ { "log-file", 1, 0, 'L'},
};
int c, opt_id;
pj_status_t status;
@@ -1190,7 +1214,7 @@
icedemo.opt.comp_cnt = 1;
icedemo.opt.max_host = -1;
- while((c=pj_getopt_long(argc,argv, "c:n:s:t:u:p:H:hTFR", long_options, &opt_id))!=-1) {
+ while((c=pj_getopt_long(argc,argv, "c:n:s:t:u:p:H:L:hTFR", long_options, &opt_id))!=-1) {
switch (c) {
case 'c':
icedemo.opt.comp_cnt = atoi(pj_optarg);
@@ -1229,6 +1253,9 @@
case 'R':
icedemo.opt.regular = PJ_TRUE;
break;
+ case 'L':
+ icedemo.opt.log_file = pj_optarg;
+ break;
default:
printf("Argument \"%s\" is not valid. Use -h to see help",
argv[pj_optind]);