Index: /pjproject/trunk/pjsip-apps/src/pjsip-perf/handler_options.c
===================================================================
--- /pjproject/trunk/pjsip-apps/src/pjsip-perf/handler_options.c	(revision 258)
+++ /pjproject/trunk/pjsip-apps/src/pjsip-perf/handler_options.c	(revision 259)
@@ -114,4 +114,6 @@
     pjsip_tx_data *tdata;
 
+    PJ_LOG(5,(THIS_FILE,"Sending OPTIONS request.."));
+
     status = pjsip_endpt_create_request( settings.endpt, 
 					 &pjsip_options_method,
Index: /pjproject/trunk/pjsip-apps/src/pjsip-perf/main.c
===================================================================
--- /pjproject/trunk/pjsip-apps/src/pjsip-perf/main.c	(revision 258)
+++ /pjproject/trunk/pjsip-apps/src/pjsip-perf/main.c	(revision 259)
@@ -46,4 +46,6 @@
     settings.thread_cnt = 1;
     settings.local_port = 5060;
+    settings.log_level = 3;
+    settings.app_log_level = 3;
 
     pjsip_method_set(&settings.method, PJSIP_OPTIONS_METHOD);
@@ -89,4 +91,128 @@
 }
 
+/*****************************************************************************
+ * This is a simple module to count and log messages 
+ */
+static void on_rx_msg(pjsip_rx_data *rdata)
+{
+    PJ_LOG(5,(THIS_FILE, "RX %d bytes %s from %s:%d:\n"
+			 "%s\n"
+			 "--end msg--",
+			 rdata->msg_info.len,
+			 pjsip_rx_data_get_info(rdata),
+			 rdata->pkt_info.src_name,
+			 rdata->pkt_info.src_port,
+			 rdata->msg_info.msg_buf));
+}
+
+static void on_tx_msg(pjsip_tx_data *tdata)
+{
+    PJ_LOG(5,(THIS_FILE, "TX %d bytes %s to %s:%d:\n"
+			 "%s\n"
+			 "--end msg--",
+			 (tdata->buf.cur - tdata->buf.start),
+			 pjsip_tx_data_get_info(tdata),
+			 tdata->tp_info.dst_name,
+			 tdata->tp_info.dst_port,
+			 tdata->buf.start));
+}
+
+static pj_bool_t mod_counter_on_rx_request(pjsip_rx_data *rdata)
+{
+    settings.rx_req++;
+    on_rx_msg(rdata);
+    return PJ_FALSE;
+}
+
+static pj_bool_t mod_counter_on_rx_response(pjsip_rx_data *rdata)
+{
+    settings.rx_res++;
+    on_rx_msg(rdata);
+    return PJ_FALSE;
+}
+
+static pj_status_t mod_counter_on_tx_request(pjsip_tx_data *tdata)
+{
+    settings.tx_req++;
+    on_tx_msg(tdata);
+    return PJ_SUCCESS;
+}
+
+static pj_status_t mod_counter_on_tx_response(pjsip_tx_data *tdata)
+{
+    settings.tx_res++;
+    on_tx_msg(tdata);
+    return PJ_SUCCESS;
+}
+
+static pjsip_module mod_counter = 
+{
+    NULL, NULL,				/* prev, next.		*/
+    { "mod-counter", 11 },		/* Name.		*/
+    -1,					/* Id			*/
+    PJSIP_MOD_PRIORITY_TRANSPORT_LAYER-1,/* Priority	        */
+    NULL,				/* load()		*/
+    NULL,				/* start()		*/
+    NULL,				/* stop()		*/
+    NULL,				/* unload()		*/
+    &mod_counter_on_rx_request,		/* on_rx_request()	*/
+    &mod_counter_on_rx_response,	/* on_rx_response()	*/
+    &mod_counter_on_tx_request,		/* on_tx_request.	*/
+    &mod_counter_on_tx_response,	/* on_tx_response()	*/
+    NULL,				/* on_tsx_state()	*/
+
+};
+
+
+/*****************************************************************************
+ * Console application custom logging:
+ */
+
+
+static FILE *log_file;
+static void app_log_writer(int level, const char *buffer, int len)
+{
+    /* Write to both stdout and file. */
+    if (level <= settings.app_log_level)
+	pj_log_write(level, buffer, len);
+
+    if (log_file) {
+	fwrite(buffer, len, 1, log_file);
+	fflush(log_file);
+    }
+}
+
+
+static pj_status_t app_logging_init(void)
+{
+    /* Redirect log function to ours */
+
+    pj_log_set_log_func( &app_log_writer );
+
+    /* If output log file is desired, create the file: */
+
+    if (settings.log_file) {
+	log_file = fopen(settings.log_file, "wt");
+	if (log_file == NULL) {
+	    PJ_LOG(1,(THIS_FILE, "Unable to open log file %s", 
+		      settings.log_file));   
+	    return -1;
+	}
+    }
+
+    return PJ_SUCCESS;
+}
+
+
+void app_logging_shutdown(void)
+{
+    /* Close logging file, if any: */
+    if (log_file) {
+	fclose(log_file);
+	log_file = NULL;
+    }
+}
+
+
 /* Initialize */
 static pj_status_t initialize(void)
@@ -95,4 +221,8 @@
     int i;
     pj_status_t status;
+
+    /* Init logging */
+    if (app_logging_init() != PJ_SUCCESS)
+	return -1;
 
     /* Create UDP transport. */
@@ -151,4 +281,11 @@
 
 
+    /* Register message counter module. */
+    status = pjsip_endpt_register_module(settings.endpt, &mod_counter);
+    if (status != PJ_SUCCESS) {
+	app_perror(THIS_FILE, "Unable to register module", status);
+	return status;
+    }
+
     /* Start worker thread. */
     for (i=0; i<settings.thread_cnt; ++i) {
@@ -161,5 +298,5 @@
     }
 
-    pj_log_set_level(3);
+    pj_log_set_level(settings.log_level);
     return PJ_SUCCESS;
 }
@@ -221,4 +358,9 @@
     puts("  --help              Display this help screen");
     puts("  --version           Display version info");
+    puts("");
+    puts("Logging options:");
+    puts("  --log-level=N       Set log verbosity (default=3)");
+    puts("  --app-log-level=N   Set screen log verbosity (default=3)");
+    puts("  --log-file=FILE     Save log to FILE");
     puts("");
     puts("SIP options:");
@@ -245,4 +387,7 @@
 	OPT_HELP,
 	OPT_VERSION,
+	OPT_LOG_LEVEL,
+	OPT_APP_LOG_LEVEL,
+	OPT_LOG_FILE,
 	OPT_LOCAL_PORT,
 	OPT_STATELESS,
@@ -255,4 +400,7 @@
 	{ "help",	    0, 0, OPT_HELP},
 	{ "version",	    0, 0, OPT_VERSION},
+	{ "log-level",	    1, 0, OPT_LOG_LEVEL},
+	{ "app-log-level",  1, 0, OPT_APP_LOG_LEVEL},
+	{ "log-file",	    1, 0, OPT_LOG_FILE},
 	{ "local-port",	    1, 0, OPT_LOCAL_PORT},
 	{ "stateless",	    0, 0, OPT_STATELESS},
@@ -276,4 +424,16 @@
 	    pj_dump_config();
 	    return PJ_EINVAL;
+
+	case OPT_LOG_LEVEL:
+	    settings.log_level = atoi(optarg);
+	    break;
+
+	case OPT_APP_LOG_LEVEL:
+	    settings.app_log_level = atoi(optarg);
+	    break;
+
+	case OPT_LOG_FILE:
+	    settings.log_file = optarg;
+	    break;
 
 	case OPT_LOCAL_PORT:
@@ -417,4 +577,5 @@
     pj_status_t status = PJ_SUCCESS;
     pjsip_cred_info cred_info[1];
+    pj_time_val elapsed;
 
     unsigned i;
@@ -433,4 +594,5 @@
     batch->failed = 0;
     pj_gettimeofday(&batch->start_time);
+    batch->spawned_time = batch->start_time;
 
     pj_list_push_back(&sess->active_list, batch);
@@ -454,7 +616,16 @@
 
 	batch->started++;
+
+	elapsed.sec = elapsed.msec = 0;
+	pjsip_endpt_handle_events(settings.endpt, &elapsed);
     }
 
     pj_gettimeofday(&batch->spawned_time);
+
+    /// 
+    elapsed = batch->spawned_time;
+    PJ_TIME_VAL_SUB(elapsed, batch->start_time);
+    PJ_LOG(2,(THIS_FILE, "%d requests sent in %d ms", batch->started,
+			 PJ_TIME_VAL_MSEC(elapsed)));
 
     sess->total_created += batch->started;
@@ -480,5 +651,5 @@
 static void start_session(pj_bool_t auto_repeat)
 {
-    pj_time_val interval = { 1, 0 };
+    pj_time_val interval = { 0, 0 };
     pj_pool_t *pool;
     session *sess;
@@ -501,5 +672,6 @@
     settings.session = sess;
 
-    spawn_batch(NULL, NULL);
+    settings.timer.cb = &spawn_batch;
+    pjsip_endpt_schedule_timer( settings.endpt, &settings.timer, &interval);
 }
 
@@ -523,4 +695,8 @@
 	    settings.duration);
 
+    printf("| Total tx requests:  %-7u rx requests:  %-7u                          |\n",
+	   settings.tx_req, settings.rx_req);
+    printf("|       tx responses: %-7u rx responses: %-7u                          |\n",
+	   settings.tx_res, settings.rx_res);
     puts  ("+--------------------------------------+-------------------------------------+");
     puts  ("|          Test Settings               |           Misc Commands:            |");
@@ -532,5 +708,5 @@
     puts  ("|                              Test Commands                                 |");
     puts  ("|                                                                            |");
-    puts  ("|  s   Start single test batch                                               |");
+    puts  ("|  s   Start single test batch             c  Clear counters                 |");
     puts  ("| sc   Start continuous test               x  Stop continuous tests          |");
     puts  ("+----------------------------------------------------------------------------+");
@@ -592,7 +768,15 @@
 	    if (settings.session) {
 		settings.session->stopping = 1;
+		puts("Stopping sessions...");
 	    } else {
 		PJ_LOG(3,(THIS_FILE,"Error: no sessions"));
 	    }
+	    break;
+
+	case 'c':
+	    /* Clear counters */
+	    settings.rx_req = settings.rx_res = settings.tx_req = 
+		settings.tx_res = 0;
+	    puts("Counters cleared");
 	    break;
 
Index: /pjproject/trunk/pjsip-apps/src/pjsip-perf/pjsip_perf.h
===================================================================
--- /pjproject/trunk/pjsip-apps/src/pjsip-perf/pjsip_perf.h	(revision 258)
+++ /pjproject/trunk/pjsip-apps/src/pjsip-perf/pjsip_perf.h	(revision 259)
@@ -36,11 +36,13 @@
     PJ_DECL_LIST_MEMBER(struct batch);
 
-    unsigned	 rate;
-    unsigned	 started;
-    unsigned	 success;
-    unsigned	 failed;
-    pj_time_val	 start_time;
-    pj_time_val	 spawned_time;
-    pj_time_val	 end_time;
+    unsigned	 rate;		/**< How many tasks to perform		    */
+
+    unsigned	 started;	/**< # of tasks started.		    */
+    unsigned	 success;	/**< # of tasks completed successfully.	    */
+    unsigned	 failed;	/**< # of failed tasks.			    */
+
+    pj_time_val	 start_time;	/**< Start time of the tests.		    */
+    pj_time_val	 spawned_time;	/**< Time when all tasks has been started.  */
+    pj_time_val	 end_time;	/**< Time when all tasks has completed.	    */
 };
 
@@ -113,4 +115,9 @@
     pj_mutex_t	    *mutex;
 
+    /* Misc: */
+    int		     log_level;
+    int		     app_log_level;
+    char	    *log_file;
+
     /* Network: */
     int		     local_port;
@@ -147,4 +154,10 @@
     session	    *session;
     pj_timer_entry   timer;
+
+    /* Counters: */
+    pj_uint32_t	     tx_req;
+    pj_uint32_t	     tx_res;
+    pj_uint32_t	     rx_req;
+    pj_uint32_t	     rx_res;
 };
 
