Perf: Protocol to measure BIRD performance internally

This protocol is highly experimental and nobody should use it in
production. Anyway it may help you getting some insight into what eats
so much time in filter processing.

6 files changed, 598 insertions, 0 deletions

diff --git a/proto/perf/Doc b/proto/perf/Doc
new file mode 100644
index 00000000..cfda309c
--- /dev/null
+++ b/proto/perf/Doc
@@ -0,0 +1 @@
+S perf.c
diff --git a/proto/perf/Makefile b/proto/perf/Makefile
new file mode 100644
index 00000000..7877fb19
--- /dev/null
+++ b/proto/perf/Makefile
@@ -0,0 +1,6 @@
+src := perf.c
+obj := $(src-o-files)
+$(all-daemon)
+$(cf-local)
+
+tests_objs := $(tests_objs) $(src-o-files)
diff --git a/proto/perf/config.Y b/proto/perf/config.Y
new file mode 100644
index 00000000..617b2233
--- /dev/null
+++ b/proto/perf/config.Y
@@ -0,0 +1,58 @@
+/*
+ *	BIRD -- Benchmarking Dummy Protocol Configuration
+ *
+ *	(c) 2018 Maria Matejka <mq@jmq.cz>
+ *
+ *	Can be freely distributed and used under the terms of the GNU GPL.
+ */
+
+CF_HDR
+
+#include "filter/filter.h"
+#include "proto/perf/perf.h"
+
+CF_DEFINES
+
+#define PERF_CFG ((struct perf_config *) this_proto)
+
+CF_DECLS
+
+CF_KEYWORDS(PERF, EXP, FROM, TO, REPEAT, THRESHOLD, MIN, MAX, KEEP, MODE, IMPORT, EXPORT)
+
+CF_GRAMMAR
+
+proto: perf_proto '}' ;
+
+perf_proto_start: proto_start PERF
+{
+  this_proto = proto_config_new(&proto_perf, $1);
+  PERF_CFG->from = 10;
+  PERF_CFG->to = 20;
+  PERF_CFG->repeat = 4;
+  PERF_CFG->threshold_max = 500 MS_;
+  PERF_CFG->threshold_min = 1 MS_;
+  PERF_CFG->keep = 0;
+  PERF_CFG->mode = PERF_MODE_IMPORT;
+};
+
+perf_proto:
+   perf_proto_start proto_name '{'
+ | perf_proto perf_proto_item ';'
+ ;
+
+perf_proto_item:
+   proto_channel { this_proto->net_type = $1->net_type; }
+ | EXP FROM NUM { PERF_CFG->from = $3; }
+ | EXP TO NUM { PERF_CFG->to = $3; }
+ | REPEAT NUM { PERF_CFG->repeat = $2; }
+ | THRESHOLD MIN expr_us { PERF_CFG->threshold_min = $3; }
+ | THRESHOLD MAX expr_us { PERF_CFG->threshold_max = $3; }
+ | KEEP bool { PERF_CFG->keep = $2; }
+ | MODE IMPORT { PERF_CFG->mode = PERF_MODE_IMPORT; }
+ | MODE EXPORT { PERF_CFG->mode = PERF_MODE_EXPORT; }
+;
+
+
+CF_CODE
+
+CF_END
diff --git a/proto/perf/parse.pl b/proto/perf/parse.pl
new file mode 100755
index 00000000..d91c5654
--- /dev/null
+++ b/proto/perf/parse.pl
@@ -0,0 +1,169 @@
+#!/usr/bin/perl
+
+use File::Temp ();
+
+package row;
+
+use Moose;
+
+has 'exp' => ( is => 'ro', 'isa' => 'Num' );
+has 'gen' => ( is => 'ro', 'isa' => 'Num' );
+has 'temp' => ( is => 'ro', 'isa' => 'Num' );
+has 'update' => ( is => 'ro', 'isa' => 'Num' );
+has 'withdraw' => ( is => 'ro', 'isa' => 'Num' );
+
+sub reduce {
+  my $self = shift;
+
+  my $N = 1 << $self->exp;
+  return row->new(
+    exp => $self->exp,
+    gen => $self->gen / $N,
+    temp => $self->temp / $N,
+    update => $self->update / $N,
+    withdraw => $self->withdraw / $N
+  );
+}
+
+sub dump {
+  my ($self, $fh) = @_;
+
+  print $fh join ",", $self->exp, $self->gen, $self->temp, $self->update, $self->withdraw;
+  print $fh "\n";
+}
+
+package results;
+
+use Moose;
+
+has 'name' => (
+  is => 'ro',
+  isa => 'Str',
+  required => 1,
+);
+
+has 'date' => (
+  is => 'ro',
+  isa => 'Str',
+  required => 1,
+);
+
+has 'reduced' => (
+  is => 'ro',
+  isa => 'Bool',
+  default => 0,
+);
+
+has 'rows' => (
+  is => 'ro',
+  isa => 'ArrayRef[row]',
+  default => sub { [] },
+);
+
+has 'stub' => (
+  is => 'ro',
+  isa => 'Str',
+  lazy => 1,
+  builder => '_build_stub',
+);
+
+sub _build_stub {
+  my $self = shift;
+
+  my $date = $self->date;
+  my $name = $self->name;
+
+  my $reduced = "-reduced" if $self->reduced;
+
+  my $stub = $date . "-" . $name . $reduced;
+
+  $stub =~ tr/a-zA-Z0-9_-/@/c;
+  return $stub;
+}
+
+sub add {
+  my $self = shift;
+  push @{$self->rows}, row->new(@_);
+}
+
+sub reduce {
+  my $self = shift;
+
+  return $self if $self->reduced;
+
+  return results->new(
+    name => $self->name,
+    date => $self->date,
+    reduced => 1,
+    rows => [
+      map { $_->reduce } @{$self->rows}
+    ],
+  );
+}
+
+sub dump {
+  my $self = shift;
+  my $fn = $self->stub . ".csv";
+
+  open my $CSV, ">", $fn;
+  map {
+    $_->dump($CSV);
+    } @{$self->rows};
+
+  close $CSV;
+  return $fn;
+}
+
+sub draw {
+  my $self = shift;
+
+  my $csv = $self->dump();
+  my $svg = $self->stub . ".svg";
+
+  my $title = $self->name;
+  $title =~ s/_/ /g;
+
+  open PLOT, "|-", "gnuplot -p";
+  print PLOT "set terminal svg;\n";
+  print PLOT "set output '$svg';\n";
+  print PLOT "set title '$title';\n";
+  print PLOT "set datafile separator ',';\n";
+  print PLOT "set jitter over 0.3 spread 0.3;\n";
+  print PLOT "plot '$csv' using 1:2 title 'gen', '$csv' using 1:3 title 'temp', '$csv' using 1:4 title 'update', '$csv' using 1:5 title 'withdraw';\n";
+  close PLOT;
+}
+
+package main;
+
+my %results;
+my @done;
+
+while (<>) {
+  if (m/(\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}).*?Perf (.+) starting$/) {
+    my $date = $1;
+    my $name = $2;
+    die "Garbled input data" if exists $results{$name};
+    $results{$name} = results->new(name => $name, date => $date);
+    next;
+  }
+
+  if (m/Perf (.+) done with exp=(\d+)$/) {
+    my $name = $1;
+    die "Garbled input data" unless exists $results{$name};
+    push @done, $results{$name};
+    delete $results{$name};
+    next;
+  }
+
+  my ($name, $exp, $gen, $temp, $update, $withdraw) = m/Perf (.+) exp=(\d+) times: gen=(\d+) temp=(\d+) update=(\d+) withdraw=(\d+)$/ or next;
+
+  exists $results{$name} or die "Garbled input data";
+
+  $results{$name}->add(exp => $exp, gen => $gen, temp => $temp, update => $update, withdraw => $withdraw);
+}
+
+scalar %results and die "Incomplete input data";
+
+foreach my $res (@done) {
+  $res->reduce->draw();
+}
diff --git a/proto/perf/perf.c b/proto/perf/perf.c
new file mode 100644
index 00000000..6741f7cb
--- /dev/null
+++ b/proto/perf/perf.c
@@ -0,0 +1,319 @@
+/*
+ *	BIRD -- Table-to-Table Routing Protocol a.k.a Pipe
+ *
+ *	(c) 1999--2000 Martin Mares <mj@ucw.cz>
+ *
+ *	Can be freely distributed and used under the terms of the GNU GPL.
+ */
+
+/**
+ * DOC: Perf
+ *
+ * Run this protocol to measure route import and export times.
+ * Generates a load of dummy routes and measures time to import.
+ */
+
+#undef LOCAL_DEBUG
+
+#include "nest/bird.h"
+#include "nest/iface.h"
+#include "nest/protocol.h"
+#include "nest/route.h"
+#include "nest/cli.h"
+#include "conf/conf.h"
+#include "filter/filter.h"
+#include "lib/string.h"
+
+#include "perf.h"
+
+#include <stdlib.h>
+#include <time.h>
+
+#define PLOG(msg, ...) log(L_INFO "Perf %s " msg, p->p.name, ##__VA_ARGS__)
+
+static inline void
+random_data(void *p, uint len)
+{
+  uint ints = (len + sizeof(int) - 1) / sizeof(int);
+  int *d = alloca(sizeof(uint) * ints);
+  for (uint i=0; i<ints; i++)
+    d[i] = random();
+
+  memcpy(p, d, len);
+}
+
+static ip_addr
+random_gw(net_addr *prefix)
+{
+  ASSERT(net_is_ip(prefix));
+  ip_addr px = net_prefix(prefix);
+  ip_addr mask = net_pxmask(prefix);
+
+  ip_addr out;
+  random_data(&out, sizeof(ip_addr));
+
+  if (ipa_is_ip4(px))
+    out = ipa_and(out, ipa_from_ip4(ip4_mkmask(32)));
+
+  return ipa_or(ipa_and(px, mask), ipa_and(out, ipa_not(mask)));
+}
+
+static net_addr_ip4
+random_net_ip4(void)
+{
+  u32 x; random_data(&x, sizeof(u32));
+  x &= ((1 << 20) - 1);
+  uint pxlen = u32_log2(x) + 5;
+
+  ip4_addr px; random_data(&px, sizeof(ip4_addr));
+
+  net_addr_ip4 out = {
+    .type = NET_IP4,
+    .pxlen = pxlen,
+    .length = sizeof(net_addr_ip4),
+    .prefix = ip4_and(ip4_mkmask(pxlen), px),
+  };
+
+  if (!net_validate((net_addr *) &out))
+    return random_net_ip4();
+
+  int c = net_classify((net_addr *) &out);
+  if ((c < 0) || !(c & IADDR_HOST) || ((c & IADDR_SCOPE_MASK) <= SCOPE_LINK))
+    return random_net_ip4();
+
+  return out;
+}
+
+struct perf_random_routes {
+  net_addr net;
+  rte *ep;
+  struct rta a;
+};
+
+static inline s64 timediff(struct timespec *begin, struct timespec *end)
+{ return (end->tv_sec - begin->tv_sec) * (s64) 1000000000 + end->tv_nsec - begin->tv_nsec; }
+
+static void
+perf_ifa_notify(struct proto *P, uint flags, struct ifa *ad)
+{
+  struct perf_proto *p = (struct perf_proto *) P;
+
+  if (ad->flags & IA_SECONDARY)
+    return;
+
+  if (p->ifa && p->ifa == ad && (flags & IF_CHANGE_DOWN)) {
+    p->ifa = NULL;
+    if (ev_active(p->loop))
+      ev_postpone(p->loop);
+
+    return;
+  }
+
+  if (!p->ifa && (flags & IF_CHANGE_UP)) {
+    p->ifa = ad;
+    ev_schedule(p->loop);
+    PLOG("starting");
+    return;
+  }
+}
+
+static void
+perf_loop(void *data)
+{
+  struct proto *P = data;
+  struct perf_proto *p = data;
+
+  const uint N = 1U << p->exp;
+  const uint offset = sizeof(net_addr) + RTA_MAX_SIZE;
+
+  if (!p->run) {
+    ASSERT(p->data == NULL);
+    p->data = xmalloc(offset * N);
+    bzero(p->data, offset * N);
+    p->stop = 1;
+  }
+
+  ip_addr gw = random_gw(&p->ifa->prefix);
+
+  struct timespec ts_begin, ts_generated, ts_rte, ts_update, ts_withdraw;
+
+  clock_gettime(CLOCK_MONOTONIC, &ts_begin);
+
+  for (uint i=0; i<N; i++) {
+    struct perf_random_routes *prr = p->data + offset * i;
+    *((net_addr_ip4 *) &prr->net) = random_net_ip4();
+
+    rta *a = &prr->a;
+    bzero(a, RTA_MAX_SIZE);
+
+    a->src = p->p.main_source;
+    a->source = RTS_PERF;
+    a->scope = SCOPE_UNIVERSE;
+    a->dest = RTD_UNICAST;
+
+    a->nh.iface = p->ifa->iface;
+    a->nh.gw = gw;
+    a->nh.weight = 1;
+  }
+
+  clock_gettime(CLOCK_MONOTONIC, &ts_generated);
+
+  for (uint i=0; i<N; i++) {
+    struct perf_random_routes *prr = p->data + offset * i;
+    prr->ep = rte_get_temp(&prr->a);
+    prr->ep->pflags = 0;
+  }
+
+  clock_gettime(CLOCK_MONOTONIC, &ts_rte);
+
+  for (uint i=0; i<N; i++) {
+    struct perf_random_routes *prr = p->data + offset * i;
+    rte_update(P, &prr->net, prr->ep);
+  }
+
+  clock_gettime(CLOCK_MONOTONIC, &ts_update);
+
+  if (!p->keep)
+    for (uint i=0; i<N; i++) {
+      struct perf_random_routes *prr = p->data + offset * i;
+      rte_update(P, &prr->net, NULL);
+    }
+
+  clock_gettime(CLOCK_MONOTONIC, &ts_withdraw);
+
+  s64 gentime = timediff(&ts_begin, &ts_generated);
+  s64 temptime = timediff(&ts_generated, &ts_rte);
+  s64 updatetime = timediff(&ts_rte, &ts_update);
+  s64 withdrawtime = timediff(&ts_update, &ts_withdraw);
+
+  if (updatetime NS >= p->threshold_min)
+    PLOG("exp=%u times: gen=%lu temp=%lu update=%lu withdraw=%lu",
+	p->exp, gentime, temptime, updatetime, withdrawtime);
+
+  if (updatetime NS < p->threshold_max)
+    p->stop = 0;
+
+  if ((updatetime NS < p->threshold_min) || (++p->run == p->repeat)) {
+    xfree(p->data);
+    p->data = NULL;
+
+    if (p->stop || (p->exp == p->to)) {
+      PLOG("done with exp=%u", p->exp);
+      return;
+    }
+
+    p->run = 0;
+    p->exp++;
+  }
+
+  ev_schedule(p->loop);
+}
+
+static void
+perf_rt_notify(struct proto *P, struct channel *c UNUSED, struct network *net UNUSED, struct rte *new UNUSED, struct rte *old UNUSED)
+{
+  struct perf_proto *p = (struct perf_proto *) P;
+  p->exp++;
+  return;
+}
+
+static void
+perf_feed_begin(struct channel *c, int initial UNUSED)
+{
+  struct perf_proto *p = (struct perf_proto *) c->proto;
+
+  p->run++;
+  p->data = xmalloc(sizeof(struct timespec));
+  p->exp = 0;
+
+  clock_gettime(CLOCK_MONOTONIC, p->data);
+}
+
+static void
+perf_feed_end(struct channel *c)
+{
+  struct perf_proto *p = (struct perf_proto *) c->proto;
+  struct timespec ts_end;
+  clock_gettime(CLOCK_MONOTONIC, &ts_end);
+
+  s64 feedtime = timediff(p->data, &ts_end);
+
+  PLOG("feed n=%lu time=%lu", p->exp, feedtime);
+
+  if (p->run < p->repeat)
+    channel_request_feeding(c);
+  else
+    PLOG("feed done");
+}
+
+static struct proto *
+perf_init(struct proto_config *CF)
+{
+  struct proto *P = proto_new(CF);
+
+  P->main_channel = proto_add_channel(P, proto_cf_main_channel(CF));
+
+  struct perf_proto *p = (struct perf_proto *) P;
+
+  p->loop = ev_new_init(P->pool, perf_loop, p);
+
+  struct perf_config *cf = (struct perf_config *) CF;
+
+  p->threshold_min = cf->threshold_min;
+  p->threshold_max = cf->threshold_max;
+  p->from = cf->from;
+  p->to = cf->to;
+  p->repeat = cf->repeat;
+  p->keep = cf->keep;
+  p->mode = cf->mode;
+
+  switch (p->mode) {
+    case PERF_MODE_IMPORT:
+      P->ifa_notify = perf_ifa_notify;
+      break;
+    case PERF_MODE_EXPORT:
+      P->rt_notify = perf_rt_notify;
+      P->feed_begin = perf_feed_begin;
+      P->feed_end = perf_feed_end;
+      break;
+  }
+
+  return P;
+}
+
+static int
+perf_start(struct proto *P)
+{
+  struct perf_proto *p = (struct perf_proto *) P;
+
+  p->ifa = NULL;
+  p->run = 0;
+  p->exp = p->from;
+  ASSERT(p->data == NULL);
+
+  return PS_UP;
+}
+
+static int
+perf_reconfigure(struct proto *P UNUSED, struct proto_config *CF UNUSED)
+{
+  return 0;
+}
+
+static void
+perf_copy_config(struct proto_config *dest UNUSED, struct proto_config *src UNUSED)
+{
+}
+
+struct protocol proto_perf = {
+  .name = 		"Perf",
+  .template =		"perf%d",
+  .class =		PROTOCOL_PERF,
+  .channel_mask = 	NB_IP,
+  .proto_size =		sizeof(struct perf_proto),
+  .config_size = 	sizeof(struct perf_config),
+  .init =		perf_init,
+  .start =		perf_start,
+  .reconfigure = 	perf_reconfigure,
+  .copy_config =	perf_copy_config,
+};
diff --git a/proto/perf/perf.h b/proto/perf/perf.h
new file mode 100644
index 00000000..301c6110
--- /dev/null
+++ b/proto/perf/perf.h
@@ -0,0 +1,45 @@
+/*
+ *	BIRD -- Benchmarking Dummy Protocol
+ *
+ *	(c) 2018 Maria Matejka <mq@jmq.cz>
+ *
+ *	Can be freely distributed and used under the terms of the GNU GPL.
+ */
+
+#ifndef _BIRD_PERF_H_
+#define _BIRD_PERF_H_
+
+enum perf_mode {
+  PERF_MODE_IMPORT,
+  PERF_MODE_EXPORT,
+};
+
+struct perf_config {
+  struct proto_config p;
+  btime threshold_min;
+  btime threshold_max;
+  uint from;
+  uint to;
+  uint repeat;
+  uint keep;
+  enum perf_mode mode;
+};
+
+struct perf_proto {
+  struct proto p;
+  struct ifa *ifa;
+  void *data;
+  event *loop;
+  btime threshold_min;
+  btime threshold_max;
+  uint from;
+  uint to;
+  uint repeat;
+  uint run;
+  uint exp;
+  uint stop;
+  uint keep;
+  enum perf_mode mode;
+};
+
+#endif