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/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]);