On Fri, 1 May 2020, [email protected] wrote:
> > From: richard.n.procter () gmail ! com
> > This implements ping(1)-like summary statistics for tcpbench(1), e.g.
> >
> > ^C
> > --- localhost tcpbench statistics ---
> > 1099642814 bytes sent over 4.126 seconds
> > bandwidth min/avg/max/std-dev = 1228.131/2117.309/2491.399/517.779 Mbps
>
> Std-dev assumes a Gaussian distribution which is unlikely if there are issues.
> (I would agree that a working LAN link would have very low std-dev.)
Hi, thanks for the feedback.
I believe the standard deviation is well-defined for any random variable
that has a mean[0]; I'm happy to be corrected.
> Percentiles would be more informative and avoids the Gaussian assumption.
I agree percentiles would also be useful but that is a next-step.
> TCP also benefits/suffers from slowstart, which would bias any short-term
> measures. Why not suggest users just "tcpbench -r 200" and compute
> their own statistics? (Note your example above is probably showing TCP
> slowstart behaviour).
Anyone remains free to compute their own stats (but I know from experience
that this is tedious, hence this patch).
Regarding slow start: as tcpbench(1) benchmarks TCP, the stats ought to
cover TCP connection performance. This includes slow start and the effects
of congestion control more generally. Slow start can be effaced from the
summary stats if desired and necessary by increasing the sample interval,
or by increasing the benchmark duration (excepting the minimum).
>
> > + printf("bandwidth min/avg/max/std-dev = %.3Lf/%.3Lf/%.3Lf/%.3Lf
> > Mbps\n",
> > + mainstats.floor_mbps, mainstats.mean_mbps, mainstats.peak_mbps,
> > + std_dev);
>
> More assumptions are implied here. How do I measure a 2400 bps link with this
> report? The precision is lost in "%.3Lf".
I highly doubt anyone needs to benchmark a 2400 bps link. The display is
in any case precise to 1000 bps.
> Some nits:
>
> > + long double mbps, old_mean_mbps, slice_mbps = 0;
>
> "long double" is a waste of bits. A double is sufficient.
Is there a cost? (Note, the type was established prior to this patch)
> > - long double mbps, slice_mbps = 0;
> > + long double mbps, old_mean_mbps, slice_mbps = 0;
> No diff for the manpage.
Good point; ping(1) mentions its stats display. See updated patch below.
> A question: when does a TCP "std-dev" tell you more than a ping "std-dev"?
As their units differ, they serve distinct questions.
cheers,
Richard.
[0] Leonard Kleinrock Queuing Systems: Volume 1: Theory John Wiley & Sons
1975; Appendix II, Probability Theory Refresher.
Index: tcpbench.1
===================================================================
RCS file: /cvs/src/usr.bin/tcpbench/tcpbench.1,v
retrieving revision 1.26
diff -u -p -u -p -r1.26 tcpbench.1
--- tcpbench.1 12 Feb 2020 14:46:36 -0000 1.26
+++ tcpbench.1 2 May 2020 11:32:13 -0000
@@ -65,14 +65,21 @@ of a listening server to connect to.
.Pp
Once connected, the client will send TCP or UDP traffic as fast as possible to
the server.
-Both the client and server will periodically display throughput
-statistics along with any kernel variables the user has selected to
+Both the client and server will periodically compute and display throughput
+statistics.
+The server starts computing these for UDP on receipt of the first datagram,
+and stops for TCP when no connections are active.
+This display also includes any kernel variables the user has selected to
sample (using the
.Fl k
option, which is only available in TCP mode).
A list of available kernel variables may be obtained using the
.Fl l
option.
+.Pp
+A summary over all throughput statistics is displayed on exit.
+Its accuracy may be increased by decreasing the
+.Ar interval .
.Pp
The options are as follows:
.Bl -tag -width Ds
Index: Makefile
===================================================================
RCS file: /cvs/src/usr.bin/tcpbench/Makefile,v
retrieving revision 1.8
diff -u -p -u -p -r1.8 Makefile
--- Makefile 9 Jul 2017 21:23:19 -0000 1.8
+++ Makefile 1 May 2020 09:57:26 -0000
@@ -1,7 +1,7 @@
# $OpenBSD: Makefile,v 1.8 2017/07/09 21:23:19 espie Exp $
PROG= tcpbench
-LDADD= -lkvm -levent
-DPADD= ${LIBKVM} ${LIBEVENT}
+LDADD= -lm -lkvm -levent
+DPADD= ${LIBM} ${LIBKVM} ${LIBEVENT}
.include <bsd.prog.mk>
Index: tcpbench.c
===================================================================
RCS file: /cvs/src/usr.bin/tcpbench/tcpbench.c,v
retrieving revision 1.61
diff -u -p -u -p -r1.61 tcpbench.c
--- tcpbench.c 12 Feb 2020 14:46:36 -0000 1.61
+++ tcpbench.c 1 May 2020 09:57:26 -0000
@@ -50,6 +50,7 @@
#include <fcntl.h>
#include <poll.h>
#include <paths.h>
+#include <math.h>
#include <kvm.h>
#include <nlist.h>
@@ -101,6 +102,8 @@ struct statctx {
u_long udp_slice_pkts;
};
+struct statctx *udp_sc; /* singleton */
+
static void signal_handler(int, short, void *);
static void saddr_ntop(const struct sockaddr *, socklen_t, char *, size_t);
static void drop_gid(void);
@@ -114,19 +117,22 @@ static void list_kvars(void);
static void check_kvar(const char *);
static char ** check_prepare_kvars(char *);
static void stats_prepare(struct statctx *);
+static void summary_display(void);
static void tcp_stats_display(unsigned long long, long double, float,
struct statctx *, struct inpcb *, struct tcpcb *, struct socket *);
static void tcp_process_slice(int, short, void *);
static void tcp_server_handle_sc(int, short, void *);
static void tcp_server_accept(int, short, void *);
-static void server_init(struct addrinfo *, struct statctx *);
+static void server_init(struct addrinfo *);
static void client_handle_sc(int, short, void *);
-static void client_init(struct addrinfo *, int, struct statctx *,
- struct addrinfo *);
+static void client_init(struct addrinfo *, int, struct addrinfo *);
static int clock_gettime_tv(clockid_t, struct timeval *);
static void udp_server_handle_sc(int, short, void *);
static void udp_process_slice(int, short, void *);
static int map_tos(char *, int *);
+static void quit(int, short, void *);
+static void wrapup(int);
+
/*
* We account the mainstats here, that is the stats
* for all connections, all variables starting with slice
@@ -135,10 +141,17 @@ static int map_tos(char *, int *);
* between all slices so far.
*/
static struct {
- unsigned long long slice_bytes; /* bytes for last slice */
+ struct timeval t_first; /* first connect / packet */
+ unsigned long long total_bytes; /* bytes since t_first */
+ unsigned long long n_slices; /* slices since start */
+ unsigned long long slice_bytes; /* bytes since slice reset */
long double peak_mbps; /* peak mbps so far */
+ long double floor_mbps; /* floor mbps so far */
+ long double mean_mbps; /* mean mbps so far */
+ long double nvariance_mbps; /* for online std dev */
int nconns; /* connected clients */
struct event timer; /* process timer */
+ const char *host; /* remote server for display */
} mainstats;
/* When adding variables, also add to tcp_stats_display() */
@@ -201,10 +214,13 @@ signal_handler(int sig, short event, voi
*/
switch (sig) {
case SIGINT:
+ printf("\n");
+ wrapup(0);
+ break; /* NOTREACHED */
case SIGTERM:
case SIGHUP:
warnx("Terminated by signal %d", sig);
- exit(0);
+ wrapup(0);
break; /* NOTREACHED */
default:
errx(1, "unexpected signal %d", sig);
@@ -479,7 +495,38 @@ stats_prepare(struct statctx *sc)
if (clock_gettime_tv(CLOCK_MONOTONIC, &sc->t_start) == -1)
err(1, "clock_gettime_tv");
sc->t_last = sc->t_start;
+ if (!timerisset(&mainstats.t_first))
+ mainstats.t_first = sc->t_start;
+}
+
+static void
+summary_display(void)
+{
+ struct timeval t_cur, t_diff;
+ long double std_dev;
+ unsigned long long total_elapsed;
+ char *direction;
+
+ if (!ptb->sflag) {
+ direction = "sent";
+ printf("--- %s tcpbench statistics ---\n", mainstats.host);
+ } else {
+ direction = "received";
+ printf("--- tcpbench server statistics ---\n");
+ }
+
+ std_dev = sqrtl(mainstats.nvariance_mbps / mainstats.n_slices);
+
+ if (clock_gettime_tv(CLOCK_MONOTONIC, &t_cur) == -1)
+ err(1, "clock_gettime_tv");
+ timersub(&t_cur, &mainstats.t_first, &t_diff);
+ total_elapsed = t_diff.tv_sec * 1000 + t_diff.tv_usec / 1000;
+ printf("%llu bytes %s over %.3Lf seconds\n",
+ mainstats.total_bytes, direction, total_elapsed/1000.0L);
+ printf("bandwidth min/avg/max/std-dev = %.3Lf/%.3Lf/%.3Lf/%.3Lf Mbps\n",
+ mainstats.floor_mbps, mainstats.mean_mbps, mainstats.peak_mbps,
+ std_dev);
}
static void
@@ -546,7 +593,7 @@ static void
tcp_process_slice(int fd, short event, void *bula)
{
unsigned long long total_elapsed, since_last;
- long double mbps, slice_mbps = 0;
+ long double mbps, old_mean_mbps, slice_mbps = 0;
float bwperc;
struct statctx *sc;
struct timeval t_cur, t_diff;
@@ -554,6 +601,11 @@ tcp_process_slice(int fd, short event, v
struct tcpcb tcpcb;
struct socket sockb;
+ if (TAILQ_EMPTY(&sc_queue))
+ return; /* don't pollute stats */
+
+ mainstats.n_slices++;
+
TAILQ_FOREACH(sc, &sc_queue, entry) {
if (clock_gettime_tv(CLOCK_MONOTONIC, &t_cur) == -1)
err(1, "clock_gettime_tv");
@@ -581,51 +633,79 @@ tcp_process_slice(int fd, short event, v
/* process stats for this slice */
if (slice_mbps > mainstats.peak_mbps)
mainstats.peak_mbps = slice_mbps;
+ if (slice_mbps < mainstats.floor_mbps)
+ mainstats.floor_mbps = slice_mbps;
+ old_mean_mbps = mainstats.mean_mbps;
+ mainstats.mean_mbps += (slice_mbps - mainstats.mean_mbps) /
+ mainstats.n_slices;
+
+ /* "Welford's method" for online variance
+ * see Knuth, TAoCP Volume 2, 3rd edn., p232 */
+ mainstats.nvariance_mbps += (slice_mbps - old_mean_mbps) *
+ (slice_mbps - mainstats.mean_mbps);
+
printf("Conn: %3d Mbps: %12.3Lf Peak Mbps: %12.3Lf Avg Mbps: %12.3Lf\n",
mainstats.nconns, slice_mbps, mainstats.peak_mbps,
mainstats.nconns ? slice_mbps / mainstats.nconns : 0);
- mainstats.slice_bytes = 0;
+ mainstats.slice_bytes = 0;
set_slice_timer(mainstats.nconns > 0);
}
static void
-udp_process_slice(int fd, short event, void *v_sc)
+udp_process_slice(int fd, short event, void *bula)
{
- struct statctx *sc = v_sc;
unsigned long long total_elapsed, since_last, pps;
- long double slice_mbps;
+ long double old_mean_mbps, slice_mbps;
struct timeval t_cur, t_diff;
+ mainstats.n_slices++;
+
if (clock_gettime_tv(CLOCK_MONOTONIC, &t_cur) == -1)
err(1, "clock_gettime_tv");
- /* Calculate pps */
- timersub(&t_cur, &sc->t_start, &t_diff);
+
+ timersub(&t_cur, &udp_sc->t_start, &t_diff);
total_elapsed = t_diff.tv_sec * 1000 + t_diff.tv_usec / 1000;
- timersub(&t_cur, &sc->t_last, &t_diff);
+
+ timersub(&t_cur, &udp_sc->t_last, &t_diff);
since_last = t_diff.tv_sec * 1000 + t_diff.tv_usec / 1000;
if (since_last == 0)
return;
- slice_mbps = (sc->bytes * 8) / (since_last * 1000.0);
- pps = (sc->udp_slice_pkts * 1000) / since_last;
+
+ slice_mbps = (udp_sc->bytes * 8) / (since_last * 1000.0);
+ pps = (udp_sc->udp_slice_pkts * 1000) / since_last;
+
if (slice_mbps > mainstats.peak_mbps)
mainstats.peak_mbps = slice_mbps;
+ if (slice_mbps < mainstats.floor_mbps)
+ mainstats.floor_mbps = slice_mbps;
+ old_mean_mbps = mainstats.mean_mbps;
+ mainstats.mean_mbps += (slice_mbps - mainstats.mean_mbps) /
+ mainstats.n_slices;
+
+ /* "Welford's method" for online variance
+ * see Knuth, TAoCP Volume 2, 3rd edn., p232 */
+ mainstats.nvariance_mbps += (slice_mbps - old_mean_mbps) *
+ (slice_mbps - mainstats.mean_mbps);
+
printf("Elapsed: %11llu Mbps: %11.3Lf Peak Mbps: %11.3Lf %s PPS:
%7llu\n",
total_elapsed, slice_mbps, mainstats.peak_mbps,
ptb->sflag ? "Rx" : "Tx", pps);
/* Clean up this slice time */
- sc->t_last = t_cur;
- sc->bytes = 0;
- sc->udp_slice_pkts = 0;
+ udp_sc->t_last = t_cur;
+ udp_sc->bytes = 0;
+ udp_sc->udp_slice_pkts = 0;
+
+ mainstats.slice_bytes = 0;
set_slice_timer(1);
}
static void
-udp_server_handle_sc(int fd, short event, void *v_sc)
+udp_server_handle_sc(int fd, short event, void *bula)
{
+ static int first_read = 1;
ssize_t n;
- struct statctx *sc = v_sc;
n = read(fd, ptb->dummybuf, ptb->dummybuf_len);
if (n == 0)
@@ -638,12 +718,16 @@ udp_server_handle_sc(int fd, short event
if (ptb->vflag >= 3)
fprintf(stderr, "read: %zd bytes\n", n);
- /* If this was our first packet, start slice timer */
- if (mainstats.peak_mbps == 0)
+ if (first_read) {
+ first_read = 0;
+ stats_prepare(udp_sc);
set_slice_timer(1);
+ }
/* Account packet */
- sc->udp_slice_pkts++;
- sc->bytes += n;
+ udp_sc->udp_slice_pkts++;
+ udp_sc->bytes += n;
+ mainstats.slice_bytes += n;
+ mainstats.total_bytes += n;
}
static void
@@ -680,6 +764,7 @@ tcp_server_handle_sc(int fd, short event
fprintf(stderr, "read: %zd bytes\n", n);
sc->bytes += n;
mainstats.slice_bytes += n;
+ mainstats.total_bytes += n;
}
static void
@@ -731,10 +816,12 @@ tcp_server_accept(int fd, short event, v
sc->tcp_ts = ts;
sc->fd = sock;
stats_prepare(sc);
+
event_set(&sc->ev, sc->fd, EV_READ | EV_PERSIST,
tcp_server_handle_sc, sc);
event_add(&sc->ev, NULL);
TAILQ_INSERT_TAIL(&sc_queue, sc, entry);
+
mainstats.nconns++;
if (mainstats.nconns == 1)
set_slice_timer(1);
@@ -744,7 +831,7 @@ tcp_server_accept(int fd, short event, v
}
static void
-server_init(struct addrinfo *aitop, struct statctx *udp_sc)
+server_init(struct addrinfo *aitop)
{
char tmp[128];
int sock, on = 1;
@@ -806,7 +893,7 @@ server_init(struct addrinfo *aitop, stru
if ((ev = calloc(1, sizeof(*ev))) == NULL)
err(1, "calloc");
event_set(ev, sock, EV_READ | EV_PERSIST,
- udp_server_handle_sc, udp_sc);
+ udp_server_handle_sc, NULL);
event_add(ev, NULL);
} else {
if ((ts = calloc(1, sizeof(*ts))) == NULL)
@@ -841,30 +928,30 @@ client_handle_sc(int fd, short event, vo
if (errno == EINTR || errno == EWOULDBLOCK ||
(UDP_MODE && errno == ENOBUFS))
return;
- err(1, "write");
+ warn("write");
+ wrapup(1);
}
if (TCP_MODE && n == 0) {
fprintf(stderr, "Remote end closed connection");
- exit(1);
+ wrapup(1);
}
if (ptb->vflag >= 3)
fprintf(stderr, "write: %zd bytes\n", n);
sc->bytes += n;
mainstats.slice_bytes += n;
+ mainstats.total_bytes += n;
if (UDP_MODE)
sc->udp_slice_pkts++;
}
static void
-client_init(struct addrinfo *aitop, int nconn, struct statctx *udp_sc,
- struct addrinfo *aib)
+client_init(struct addrinfo *aitop, int nconn, struct addrinfo *aib)
{
struct statctx *sc;
struct addrinfo *ai;
char tmp[128];
int i, r, sock;
- sc = udp_sc;
for (i = 0; i < nconn; i++) {
for (sock = -1, ai = aitop; ai != NULL; ai = ai->ai_next) {
saddr_ntop(ai->ai_addr, ai->ai_addrlen, tmp,
@@ -926,13 +1013,17 @@ client_init(struct addrinfo *aitop, int
if (TCP_MODE) {
if ((sc = calloc(1, sizeof(*sc))) == NULL)
err(1, "calloc");
- }
+ } else
+ sc = udp_sc;
+
sc->fd = sock;
stats_prepare(sc);
+
event_set(&sc->ev, sc->fd, EV_WRITE | EV_PERSIST,
client_handle_sc, sc);
event_add(&sc->ev, NULL);
TAILQ_INSERT_TAIL(&sc_queue, sc, entry);
+
mainstats.nconns++;
if (mainstats.nconns == 1)
set_slice_timer(1);
@@ -998,7 +1089,27 @@ map_tos(char *s, int *val)
static void
quit(int sig, short event, void *arg)
{
- exit(0);
+ wrapup(0);
+}
+
+static void
+wrapup(int err)
+{
+ const int transfers = timerisset(&mainstats.t_first);
+ const int stats = (mainstats.floor_mbps != INFINITY);
+
+ if (transfers) {
+ if (!stats) {
+ if (UDP_MODE)
+ udp_process_slice(0, 0, NULL);
+ else
+ tcp_process_slice(0, 0, NULL);
+ }
+
+ summary_display();
+ }
+
+ exit(err);
}
int
@@ -1016,7 +1127,6 @@ main(int argc, char **argv)
struct nlist nl[] = { { "_tcbtable" }, { "" } };
const char *host = NULL, *port = DEFAULT_PORT, *srcbind = NULL;
struct event ev_sigint, ev_sigterm, ev_sighup, ev_progtimer;
- struct statctx *udp_sc = NULL;
struct sockaddr_un sock_un;
/* Init world */
@@ -1159,7 +1269,7 @@ main(int argc, char **argv)
drop_gid();
if (!ptb->sflag || ptb->Uflag)
- host = argv[0];
+ mainstats.host = host = argv[0];
if (ptb->Uflag)
if (unveil(host, "rwc") == -1)
@@ -1244,6 +1354,9 @@ main(int argc, char **argv)
err(1, "malloc");
arc4random_buf(ptb->dummybuf, ptb->dummybuf_len);
+ timerclear(&mainstats.t_first);
+ mainstats.floor_mbps = INFINITY;
+
/* Setup libevent and signals */
event_init();
signal_set(&ev_sigterm, SIGTERM, signal_handler, NULL);
@@ -1258,15 +1371,14 @@ main(int argc, char **argv)
if ((udp_sc = calloc(1, sizeof(*udp_sc))) == NULL)
err(1, "calloc");
udp_sc->fd = -1;
- stats_prepare(udp_sc);
- evtimer_set(&mainstats.timer, udp_process_slice, udp_sc);
+ evtimer_set(&mainstats.timer, udp_process_slice, NULL);
} else {
print_tcp_header();
evtimer_set(&mainstats.timer, tcp_process_slice, NULL);
}
if (ptb->sflag)
- server_init(aitop, udp_sc);
+ server_init(aitop);
else {
if (secs > 0) {
timerclear(&tv);
@@ -1274,7 +1386,7 @@ main(int argc, char **argv)
evtimer_set(&ev_progtimer, quit, NULL);
evtimer_add(&ev_progtimer, &tv);
}
- client_init(aitop, nconn, udp_sc, aib);
+ client_init(aitop, nconn, aib);
if (pledge("stdio", NULL) == -1)
err(1, "pledge");
