Various changes related to counting SSL handshake + transfer on server side. Also changes gettimeofday to clock_gettime with monotonic counter

src/conn.h

@@ -84,6 +84,7 @@ typedef struct Conn
       {
 	Time time_connect_start;	/* time connect() got called */
 	u_int num_calls_completed;	/* # of calls that completed */
+    Time ssl_handshake_connect_start;    /* time connect() got called */
       }
     basic;			/* maintained by stat/stats_basic.c */
 

src/core.c

@@ -58,6 +58,8 @@
 #ifdef HAVE_KEVENT
 #include <sys/event.h>
 
+#include <cstddef>
+
 /*
  * Older systems using kevent() always specify the time in
  * milliseconds and do not have a flag to select a different scale.
@@ -90,6 +92,9 @@
 #define MIN_IP_PORT	IPPORT_RESERVED
 #define MAX_IP_PORT	65535
 #define BITSPERLONG	(8*sizeof (u_long))
+#ifdef HAVE_SSL
+#define SSL_DATA_CONN 0x01
+#endif // HAVE_SSL
 
 struct local_addr {
 	struct in_addr ip;
@@ -1048,6 +1053,17 @@ core_init(void)
 
 #ifdef HAVE_SSL
 
+// Starts counting time after key has been generated on client side
+static void after_keygen_handshake_time(const SSL *ssl, int type, int value) {
+	struct Conn *data = 0;
+	if (type == SSL_CB_HANDSHAKE_WRITTEN) {
+		data = SSL_get_ex_data(ssl, SSL_DATA_CONN);
+		if (data) {
+			data->basic.ssl_handshake_connect_start = timer_now();
+		}
+	}
+}
+
 int
 core_ssl_connect(Conn * s)
 {
@@ -1062,6 +1078,9 @@ core_ssl_connect(Conn * s)
 		exit(-1);
 	}
 
+	SSL_set_info_callback(s->ssl, after_keygen_handshake_time);
+	SSL_set_ex_data(s->ssl, SSL_DATA_CONN, s);
+
 	ssl_err = SSL_connect(s->ssl);
 	if (ssl_err < 0) {
 		int             reason = SSL_get_error(s->ssl, ssl_err);

src/http.c

@@ -76,7 +76,7 @@ get_line (Call *c, char **bufp, size_t *buf_lenp)
   buf_len -= to_copy;
   if (s->line.iov_len + to_copy >= sizeof (s->line_buf))
     {
-      fprintf (stderr,
+      if (DBG>0) fprintf (stderr,
 	       "%s.get_line: truncating header from %lu to %lu bytes\n",
 	       prog_name, (u_long) (s->line.iov_len + to_copy),
 	       (u_long) sizeof (s->line_buf));

src/stat/basic.c

@@ -105,6 +105,7 @@ static struct {
 
 	u_int           conn_lifetime_hist[NUM_BINS];	/* histogram of
 													 * connection lifetimes */
+    Time ssl_handshake_connect_start;    /* time connect() got called */
 } basic;
 
 static u_long    num_active_conns;
@@ -214,7 +215,9 @@ conn_connected(Event_Type et, Object * obj, Any_Type reg_arg,
 	Conn           *s = (Conn *) obj;
 
 	assert(et == EV_CONN_CONNECTED && object_is_conn(s));
-	basic.conn_connect_sum += timer_now() - s->basic.time_connect_start;
+	Time t = timer_now();
+	basic.conn_connect_sum += t - s->basic.time_connect_start;
+	basic.ssl_handshake_connect_start += t - s->basic.ssl_handshake_connect_start;
 	++basic.num_connects;
 }
 
@@ -359,7 +362,8 @@ static void
 dump(void)
 {
 	Time            conn_period = 0.0, call_period = 0.0;
-	Time            conn_time = 0.0, resp_time = 0.0, xfer_time = 0.0;
+	Time            conn_time = 0.0, resp_time = 0.0, xfer_time = 0.0,
+	    ssl_hs_time = 0.0;
 	Time            call_size = 0.0, hdr_size = 0.0, reply_size =
 		0.0, footer_size = 0.0;
 	Time            lifetime_avg = 0.0, lifetime_stddev =
@@ -423,14 +427,20 @@ dump(void)
 		   1e3 * lifetime_avg,
 		   1e3 * basic.conn_lifetime_max, 1e3 * lifetime_median,
 		   1e3 * lifetime_stddev);
-	if (basic.num_connects > 0)
+	if (basic.num_connects > 0) {
 		conn_time = basic.conn_connect_sum / basic.num_connects;
+	}
+
 	printf("Connection time [ms]: connect %.1f\n", 1e3 * conn_time);
 	printf("Connection length [replies/conn]: %.3f\n",
 		   basic.num_lifetimes > 0
 		   ? total_replies / (double) basic.num_lifetimes : 0.0);
 	putchar('\n');
 
+	ssl_hs_time = basic.ssl_handshake_connect_start / basic.num_connects;
+	printf("SSL handshake time [ms]: %.3f\n", 1e3 * ssl_hs_time);
+
+	putchar('\n');
 	if (basic.num_sent > 0)
 		call_period = delta / basic.num_sent;
 	printf("Request rate: %.1f req/s (%.1f ms/req)\n",

src/timer.c

@@ -83,10 +83,9 @@ static struct List *persistent_timers = NULL;
 Time
 timer_now_forced(void)
 {
-	struct timeval  tv;
-
-	gettimeofday(&tv, 0);
-	return tv.tv_sec + tv.tv_usec * 1e-6;
+    struct timespec ts;
+	clock_gettime(CLOCK_MONOTONIC, &ts);
+	return ts.tv_sec + (ts.tv_nsec * 1e-9);
 }
 
 /*