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.

configure.ac

@@ -271,7 +271,7 @@ if test "$enable_mpls_kernel" != no ; then
   fi
 fi
 
-all_protocols="$proto_bfd babel bgp mrt ospf pipe radv rip $proto_rpki static"
+all_protocols="$proto_bfd babel bgp mrt ospf perf pipe radv rip $proto_rpki static"
 
 all_protocols=`echo $all_protocols | sed 's/ /,/g'`
 

doc/bird.sgml

@@ -25,7 +25,7 @@ configuration - something in config which is not keyword.
 Ondrej Filip <it/&lt;feela@network.cz&gt;/,
 Pavel Machek <it/&lt;pavel@ucw.cz&gt;/,
 Martin Mares <it/&lt;mj@ucw.cz&gt;/,
-Maria Jan Matejka <it/&lt;mq@jmq.cz&gt;/,
+Maria Matejka <it/&lt;mq@jmq.cz&gt;/,
 Ondrej Zajicek <it/&lt;santiago@crfreenet.org&gt;/
 </author>
 
@@ -3759,6 +3759,54 @@ protocol ospf MyOSPF {
 }
 </code>
 
+<sect>Perf
+<label id="perf">
+
+<sect1>Introduction
+<label id="perf-intro">
+
+<p>The Perf protocol is a generator of fake routes together with a time measurement
+framework. Its purpose is to check BIRD performance and to benchmark filters.
+
+<p>Import mode of this protocol runs in several steps. In each step, it generates 2^x routes,
+imports them into the appropriate table and withdraws them. The exponent x is configurable.
+It runs the benchmark several times for the same x, then it increases x by one
+until it gets too high, then it stops.
+
+<p>Export mode of this protocol repeats route refresh from table and measures how long it takes.
+
+<p>Output data is logged on info level. There is a Perl script <cf>proto/perf/parse.pl</cf>
+which may be handy to parse the data and draw some plots.
+
+<p>Implementation of this protocol is experimental. Use with caution and do not keep
+any instance of Perf in production configs for long time. The config interface is also unstable
+and may change in future versions without warning.
+
+<sect1>Configuration
+<label id="perf-config">
+
+<p><descrip>
+	<tag><label id="perf-mode">mode import|export</tag>
+	Set perf mode. Default: import
+
+	<tag><label id="perf-repeat">repeat <m/number/</tag>
+	Run this amount of iterations of the benchmark for every amount step. Default: 4
+
+	<tag><label id="perf-from">exp from <m/number/</tag>
+	Begin benchmarking on this exponent for number of generated routes in one step.
+	Default: 10
+
+	<tag><label id="perf-to">exp to <m/number/</tag>
+	Stop benchmarking on this exponent. Default: 20
+
+	<tag><label id="perf-threshold-min">threshold min <m/time/</tag>
+	If a run for the given exponent took less than this time for route import,
+	increase the exponent immediately. Default: 1 ms
+
+	<tag><label id="perf-threshold-max">threshold max <m/time/</tag>
+	If every run for the given exponent took at least this time for route import,
+	stop benchmarking. Default: 500 ms
+</descrip>
 
 <sect>Pipe
 <label id="pipe">

nest/proto.c

@@ -1379,6 +1379,9 @@ protos_build(void)
 #ifdef CONFIG_RPKI
   proto_build(&proto_rpki);
 #endif
+#ifdef CONFIG_PERF
+  proto_build(&proto_perf);
+#endif
 
   proto_pool = rp_new(&root_pool, "Protocols");
   proto_shutdown_timer = tm_new(proto_pool);

nest/protocol.h

@@ -47,6 +47,7 @@ enum protocol_class {
   PROTOCOL_KERNEL,
   PROTOCOL_OSPF,
   PROTOCOL_MRT,
+  PROTOCOL_PERF,
   PROTOCOL_PIPE,
   PROTOCOL_RADV,
   PROTOCOL_RIP,
@@ -100,7 +101,8 @@ void protos_dump_all(void);
 
 extern struct protocol
   proto_device, proto_radv, proto_rip, proto_static, proto_mrt,
-  proto_ospf, proto_pipe, proto_bgp, proto_bfd, proto_babel, proto_rpki;
+  proto_ospf, proto_perf,
+  proto_pipe, proto_bgp, proto_bfd, proto_babel, proto_rpki;
 
 /*
  *	Routing Protocol Instance

nest/route.h

@@ -428,8 +428,8 @@ typedef struct rta {
 #define RTS_PIPE 12			/* Inter-table wormhole */
 #define RTS_BABEL 13			/* Babel route */
 #define RTS_RPKI 14			/* Route Origin Authorization */
-#define RTS_MAX 15
-
+#define RTS_PERF 15			/* Perf checker */
+#define RTS_MAX 16
 
 #define RTC_UNICAST 0
 #define RTC_BROADCAST 1

proto/perf/Doc

@@ -0,0 +1 @@
+S perf.c

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)

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

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();
+}

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,
+};

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