/*
httperf -- a tool for measuring web server performance
Copyright (C) 2000 Hewlett-Packard Company
Contributed by David Mosberger-Tang <davidm@hpl.hp.com>
This file is part of httperf, a web server performance measurment
tool.
This program is free software; you can redistribute it and/or
modify it under the terms of the GNU General Public License as
published by the Free Software Foundation; either version 2 of the
License, or (at your option) any later version.
This program is distributed in the hope that it will be useful,
but WITHOUT ANY WARRANTY; without even the implied warranty of
MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU
General Public License for more details.
You should have received a copy of the GNU General Public License
along with this program; if not, write to the Free Software
Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA
02111-1307 USA
*/
/* Basic statistics collector. */
#include "config.h"
#include <assert.h>
#include <errno.h>
#include <float.h>
#include <stdio.h>
#include <httperf.h>
#include <call.h>
#include <event.h>
#include <stats.h>
/* Increase this if it does not cover at least 50% of all response
times. */
#define MAX_LIFETIME 100.0 /* max. conn. lifetime in seconds */
#define BIN_WIDTH 1e-3
#define NUM_BINS ((u_int) (MAX_LIFETIME / BIN_WIDTH))
static struct
{
u_int num_conns_issued; /* total # of connections issued */
u_int num_replies[6]; /* completion count per status class */
u_int num_client_timeouts; /* # of client timeouts */
u_int num_sock_fdunavail; /* # of times out of filedescriptors */
u_int num_sock_ftabfull; /* # of times file table was full */
u_int num_sock_refused; /* # of ECONNREFUSED */
u_int num_sock_reset; /* # of ECONNRESET */
u_int num_sock_timeouts; /* # of ETIMEDOUT */
u_int num_sock_addrunavail;/* # of EADDRNOTAVAIL */
u_int num_other_errors; /* # of other errors */
u_int max_conns; /* max # of concurrent connections */
u_int num_lifetimes;
Time conn_lifetime_sum; /* sum of connection lifetimes */
Time conn_lifetime_sum2; /* sum of connection lifetimes squared */
Time conn_lifetime_min; /* minimum connection lifetime */
Time conn_lifetime_max; /* maximum connection lifetime */
u_int num_reply_rates;
Time reply_rate_sum;
Time reply_rate_sum2;
Time reply_rate_min;
Time reply_rate_max;
u_int num_connects; /* # of completed connect()s */
Time conn_connect_sum; /* sum of connect times */
u_int num_responses;
Time call_response_sum; /* sum of response times */
Time call_xfer_sum; /* sum of response times */
u_int num_sent; /* # of requests sent */
size_t req_bytes_sent;
u_int num_received; /* # of replies received */
u_wide hdr_bytes_received; /* sum of all header bytes */
u_wide reply_bytes_received; /* sum of all data bytes */
u_wide footer_bytes_received; /* sum of all footer bytes */
u_int conn_lifetime_hist[NUM_BINS]; /* histogram of connection lifetimes */
}
basic;
static u_int num_active_conns;
static u_int num_replies; /* # of replies received in this interval */
static void
perf_sample (Event_Type et, Object *obj, Any_Type reg_arg, Any_Type call_arg)
{
Time weight = call_arg.d;
double rate;
assert (et == EV_PERF_SAMPLE);
rate = weight*num_replies;
if (verbose)
printf ("reply-rate = %-8.1f\n", rate);
basic.reply_rate_sum += rate;
basic.reply_rate_sum2 += SQUARE (rate);
if (rate < basic.reply_rate_min)
basic.reply_rate_min = rate;
if (rate > basic.reply_rate_max)
basic.reply_rate_max = rate;
++basic.num_reply_rates;
/* prepare for next sample interval: */
num_replies = 0;
}
static void
conn_timeout (Event_Type et, Object *obj, Any_Type reg_arg, Any_Type call_arg)
{
assert (et == EV_CONN_TIMEOUT);
++basic.num_client_timeouts;
}
static void
conn_fail (Event_Type et, Object *obj, Any_Type reg_arg, Any_Type call_arg)
{
static int first_time = 1;
int err = call_arg.i;
assert (et == EV_CONN_FAILED);
switch (err)
{
#ifdef __linux__
case EINVAL: /* Linux has a strange way of saying "out of fds"... */
#endif
case EMFILE: ++basic.num_sock_fdunavail; break;
case ENFILE: ++basic.num_sock_ftabfull; break;
case ECONNREFUSED: ++basic.num_sock_refused; break;
case ETIMEDOUT: ++basic.num_sock_timeouts; break;
case EPIPE:
case ECONNRESET:
++basic.num_sock_reset;
break;
default:
if (first_time)
{
first_time = 0;
fprintf (stderr, "%s: connection failed with unexpected error %d\n",
prog_name, errno);
}
++basic.num_other_errors;
break;
}
}
static void
conn_created (Event_Type et, Object *obj, Any_Type reg_arg, Any_Type c_arg)
{
++num_active_conns;
if (num_active_conns > basic.max_conns)
basic.max_conns = num_active_conns;
}
static void
conn_connecting (Event_Type et, Object *obj, Any_Type reg_arg, Any_Type c_arg)
{
Conn *s = (Conn *) obj;
assert (et == EV_CONN_CONNECTING && object_is_conn (s));
s->basic.time_connect_start = timer_now ();
++basic.num_conns_issued;
}
static void
conn_connected (Event_Type et, Object *obj, Any_Type reg_arg,
Any_Type call_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;
++basic.num_connects;
}
static void
conn_destroyed (Event_Type et, Object *obj, Any_Type reg_arg, Any_Type c_arg)
{
Conn *s = (Conn *) obj;
Time lifetime;
u_int bin;
assert (et == EV_CONN_DESTROYED && object_is_conn (s)
&& num_active_conns > 0);
if (s->basic.num_calls_completed > 0)
{
lifetime = timer_now () - s->basic.time_connect_start;
basic.conn_lifetime_sum += lifetime;
basic.conn_lifetime_sum2 += SQUARE (lifetime);
if (lifetime < basic.conn_lifetime_min)
basic.conn_lifetime_min = lifetime;
if (lifetime > basic.conn_lifetime_max)
basic.conn_lifetime_max = lifetime;
++basic.num_lifetimes;
bin = lifetime*NUM_BINS/MAX_LIFETIME;
if (bin >= NUM_BINS)
bin = NUM_BINS;
++basic.conn_lifetime_hist[bin];
}
--num_active_conns;
}
static void
send_start (Event_Type et, Object *obj, Any_Type reg_arg, Any_Type call_arg)
{
Call *c = (Call *) obj;
assert (et == EV_CALL_SEND_START && object_is_call (c));
c->basic.time_send_start = timer_now ();
}
static void
send_stop (Event_Type et, Object *obj, Any_Type reg_arg, Any_Type call_arg)
{
Call *c = (Call *) obj;
assert (et == EV_CALL_SEND_STOP && object_is_call (c));
basic.req_bytes_sent += c->req.size;
++basic.num_sent;
}
static void
recv_start (Event_Type et, Object *obj, Any_Type reg_arg, Any_Type call_arg)
{
Call *c = (Call *) obj;
Time now;
assert (et == EV_CALL_RECV_START && object_is_call (c));
now = timer_now ();
basic.call_response_sum += now - c->basic.time_send_start;
c->basic.time_recv_start = now;
++basic.num_responses;
}
static void
recv_stop (Event_Type et, Object *obj, Any_Type reg_arg, Any_Type call_arg)
{
Call *c = (Call *) obj;
int index;
assert (et == EV_CALL_RECV_STOP && object_is_call (c));
assert (c->basic.time_recv_start > 0);
basic.call_xfer_sum += timer_now () - c->basic.time_recv_start;
basic.hdr_bytes_received += c->reply.header_bytes;
basic.reply_bytes_received += c->reply.content_bytes;
basic.footer_bytes_received += c->reply.footer_bytes;
index = (c->reply.status / 100);
assert ((unsigned) index < NELEMS (basic.num_replies));
++basic.num_replies[index];
++num_replies;
++c->conn->basic.num_calls_completed;
}
static void
init (void)
{
Any_Type arg;
basic.conn_lifetime_min = DBL_MAX;
basic.reply_rate_min = DBL_MAX;
arg.l = 0;
event_register_handler (EV_PERF_SAMPLE, perf_sample, arg);
event_register_handler (EV_CONN_FAILED, conn_fail, arg);
event_register_handler (EV_CONN_TIMEOUT, conn_timeout, arg);
event_register_handler (EV_CONN_NEW, conn_created, arg);
event_register_handler (EV_CONN_CONNECTING, conn_connecting, arg);
event_register_handler (EV_CONN_CONNECTED, conn_connected, arg);
event_register_handler (EV_CONN_DESTROYED, conn_destroyed, arg);
event_register_handler (EV_CALL_SEND_START, send_start, arg);
event_register_handler (EV_CALL_SEND_STOP, send_stop, arg);
event_register_handler (EV_CALL_RECV_START, recv_start, arg);
event_register_handler (EV_CALL_RECV_STOP, recv_stop, arg);
}
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 call_size = 0.0, hdr_size = 0.0, reply_size = 0.0, footer_size = 0.0;
Time lifetime_avg = 0.0, lifetime_stddev = 0.0, lifetime_median = 0.0;
double reply_rate_avg = 0.0, reply_rate_stddev = 0.0;
int i, total_replies = 0;
Time delta, user, sys;
u_wide total_size;
Time time;
u_int n;
for (i = 1; i < NELEMS (basic.num_replies); ++i)
total_replies += basic.num_replies[i];
delta = test_time_stop - test_time_start;
if (verbose > 1)
{
printf ("\nConnection lifetime histogram (time in ms):\n");
for (i = 0; i < NUM_BINS; ++i)
if (basic.conn_lifetime_hist[i])
{
if (i > 0 && basic.conn_lifetime_hist[i - 1] == 0)
printf ("%14c\n", ':');
time = (i + 0.5)*BIN_WIDTH;
printf ("%16.1f %u\n", 1e3*time, basic.conn_lifetime_hist[i]);
}
}
printf ("\nTotal: connections %u requests %u replies %u "
"test-duration %.3f s\n",
basic.num_conns_issued, basic.num_sent, total_replies,
delta);
putchar ('\n');
if (basic.num_conns_issued)
conn_period = delta/basic.num_conns_issued;
printf ("Connection rate: %.1f conn/s (%.1f ms/conn, "
"<=%u concurrent connections)\n",
basic.num_conns_issued / delta, 1e3*conn_period, basic.max_conns);
if (basic.num_lifetimes > 0)
{
lifetime_avg = (basic.conn_lifetime_sum / basic.num_lifetimes);
if (basic.num_lifetimes > 1)
lifetime_stddev = STDDEV (basic.conn_lifetime_sum,
basic.conn_lifetime_sum2,
basic.num_lifetimes);
n = 0;
for (i = 0; i < NUM_BINS; ++i)
{
n += basic.conn_lifetime_hist[i];
if (n >= 0.5*basic.num_lifetimes)
{
lifetime_median = (i + 0.5)*BIN_WIDTH;
break;
}
}
}
printf ("Connection time [ms]: min %.1f avg %.1f max %.1f median %.1f "
"stddev %.1f\n",
basic.num_lifetimes > 0 ? 1e3 * basic.conn_lifetime_min : 0.0,
1e3 * lifetime_avg,
1e3 * basic.conn_lifetime_max, 1e3 * lifetime_median,
1e3 * lifetime_stddev);
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');
if (basic.num_sent > 0)
call_period = delta/basic.num_sent;
printf ("Request rate: %.1f req/s (%.1f ms/req)\n",
basic.num_sent / delta, 1e3*call_period);
if (basic.num_sent)
call_size = basic.req_bytes_sent / basic.num_sent;
printf ("Request size [B]: %.1f\n", call_size);
putchar ('\n');
if (basic.num_reply_rates > 0)
{
reply_rate_avg = (basic.reply_rate_sum / basic.num_reply_rates);
if (basic.num_reply_rates > 1)
reply_rate_stddev = STDDEV (basic.reply_rate_sum,
basic.reply_rate_sum2,
basic.num_reply_rates);
}
printf ("Reply rate [replies/s]: min %.1f avg %.1f max %.1f stddev %.1f "
"(%u samples)\n",
basic.num_reply_rates > 0 ? basic.reply_rate_min : 0.0,
reply_rate_avg, basic.reply_rate_max,
reply_rate_stddev, basic.num_reply_rates);
if (basic.num_responses > 0)
resp_time = basic.call_response_sum / basic.num_responses;
if (total_replies > 0)
xfer_time = basic.call_xfer_sum / total_replies;
printf ("Reply time [ms]: response %.1f transfer %.1f\n",
1e3*resp_time, 1e3*xfer_time);
if (total_replies)
{
hdr_size = basic.hdr_bytes_received / total_replies;
reply_size = basic.reply_bytes_received / total_replies;
footer_size = basic.footer_bytes_received / total_replies;
}
printf ("Reply size [B]: header %.1f content %.1f footer %.1f "
"(total %.1f)\n", hdr_size, reply_size, footer_size,
hdr_size + reply_size + footer_size);
printf ("Reply status: 1xx=%u 2xx=%u 3xx=%u 4xx=%u 5xx=%u\n",
basic.num_replies[1], basic.num_replies[2], basic.num_replies[3],
basic.num_replies[4], basic.num_replies[5]);
putchar ('\n');
user = (TV_TO_SEC (test_rusage_stop.ru_utime)
- TV_TO_SEC (test_rusage_start.ru_utime));
sys = (TV_TO_SEC (test_rusage_stop.ru_stime)
- TV_TO_SEC (test_rusage_start.ru_stime));
printf ("CPU time [s]: user %.2f system %.2f (user %.1f%% system %.1f%% "
"total %.1f%%)\n", user, sys, 100.0*user/delta, 100.0*sys/delta,
100.0*(user + sys)/delta);
total_size = (basic.req_bytes_sent
+ basic.hdr_bytes_received + basic.reply_bytes_received);
printf ("Net I/O: %.1f KB/s (%.1f*10^6 bps)\n",
total_size/delta / 1024.0, 8e-6*total_size/delta);
putchar ('\n');
printf ("Errors: total %u client-timo %u socket-timo %u "
"connrefused %u connreset %u\n"
"Errors: fd-unavail %u addrunavail %u ftab-full %u other %u\n",
(basic.num_client_timeouts + basic.num_sock_timeouts
+ basic.num_sock_fdunavail + basic.num_sock_ftabfull
+ basic.num_sock_refused + basic.num_sock_reset
+ basic.num_sock_addrunavail + basic.num_other_errors),
basic.num_client_timeouts, basic.num_sock_timeouts,
basic.num_sock_refused, basic.num_sock_reset,
basic.num_sock_fdunavail, basic.num_sock_addrunavail,
basic.num_sock_ftabfull, basic.num_other_errors);
}
Stat_Collector stats_basic =
{
"Basic statistics",
init,
no_op,
no_op,
dump
};
syntax highlighted by Code2HTML, v. 0.9.1