]> git.ozlabs.org Git - ppp.git/commitdiff
Merge pull request #422 from rfc1036/lcp-rtt
authorPaul Mackerras <paulus@ozlabs.org>
Sat, 30 Sep 2023 12:21:39 +0000 (22:21 +1000)
committerGitHub <noreply@github.com>
Sat, 30 Sep 2023 12:21:39 +0000 (22:21 +1000)
Implement logging the LCP Round Trip Time

pppd/lcp.c
pppd/pppd.8
scripts/lcp_rtt_dump [new file with mode: 0755]
scripts/lcp_rtt_exporter [new file with mode: 0644]

index c72c2ef90bb2dc10cc3970b08059ea11344016e0..d174b8fb53066e14752d0dac37ce5d1663bf28f0 100644 (file)
 #include <stdio.h>
 #include <string.h>
 #include <stdlib.h>
+#include <fcntl.h>
+#include <string.h>
+#include <time.h>
+#include <arpa/inet.h>
+#include <sys/mman.h>
 
 #include "pppd-private.h"
 #include "options.h"
 
 static void lcp_delayed_up(void *);
 
+/*
+ * These definitions relate to the measurement and logging of round-trip
+ * time (RTT) of LCP echo-requests implemented in lcp_rtt_update_buffer().
+ */
+#define LCP_RTT_MAGIC 0x19450425
+#define LCP_RTT_HEADER_LENGTH 4
+#define LCP_RTT_FILE_SIZE 8192
+#define LCP_RTT_ELEMENTS (LCP_RTT_FILE_SIZE / sizeof(u_int32_t) - LCP_RTT_HEADER_LENGTH) / 2
+
 /*
  * LCP-related command-line options.
  */
 int    lcp_echo_interval = 0;  /* Interval between LCP echo-requests */
 int    lcp_echo_fails = 0;     /* Tolerance to unanswered echo-requests */
 bool   lcp_echo_adaptive = 0;  /* request echo only if the link was idle */
+char   *lcp_rtt_file = NULL;   /* measure the RTT of LCP echo-requests */
 bool   lax_recv = 0;           /* accept control chars in asyncmap */
 bool   noendpoint = 0;         /* don't send/accept endpoint discriminator */
 
@@ -152,6 +167,9 @@ static struct option lcp_option_list[] = {
       "Set time in seconds between LCP echo requests", OPT_PRIO },
     { "lcp-echo-adaptive", o_bool, &lcp_echo_adaptive,
       "Suppress LCP echo requests if traffic was received", 1 },
+    { "lcp-rtt-file", o_string, &lcp_rtt_file,
+      "Filename for logging the round-trip time of LCP echo requests",
+      OPT_PRIO | OPT_PRIV },
     { "lcp-restart", o_int, &lcp_fsm[0].timeouttime,
       "Set time in seconds between LCP retransmissions", OPT_PRIO },
     { "lcp-max-terminate", o_int, &lcp_fsm[0].maxtermtransmits,
@@ -197,6 +215,8 @@ lcp_options lcp_hisoptions[NUM_PPP];        /* Options that we ack'd */
 static int lcp_echos_pending = 0;      /* Number of outstanding echo msgs */
 static int lcp_echo_number   = 0;      /* ID number of next echo frame */
 static int lcp_echo_timer_running = 0;  /* set if a timer is running */
+static int lcp_rtt_file_fd = 0;                /* fd for the opened LCP RTT file */
+static volatile u_int32_t *lcp_rtt_buffer = NULL; /* the mmap'ed LCP RTT file */
 
 static u_char nak_buffer[PPP_MRU];     /* where we construct a nak packet */
 
@@ -2225,6 +2245,72 @@ LcpEchoTimeout (void *arg)
     }
 }
 
+/*
+ * Log the round-trip time (RTT) of the received LCP echo-request.
+ *
+ * The header section at the beginning of lcp_rtt_file contains
+ * LCP_RTT_HEADER_LENGTH fields, each a u_int32_t in network byte order:
+ * [0] LCP_RTT_MAGIC
+ * [1] status (1: the file is open and is being written)
+ * [2] index of the most recently updated element
+ * [3] the value of the lcp-echo-interval parameter
+ *
+ * The header is followed by a ring buffer of LCP_RTT_ELEMENTS elements, each
+ * containing a pair of u_int32_t in network byte order with this content:
+ * [0] UNIX timestamp
+ * [1] bits 24-31: the number of lost LCP echo replies
+ *     bits 0-23:  the measured RTT in microseconds
+ *
+ * The timestamp is unsigned to support storing dates beyond 2038.
+ *
+ * Consumers of lcp_rtt_file are expected to:
+ * - read the complete file of arbitrary length
+ * - check the magic number
+ * - process the data elements starting at the index
+ * - ignore any elements with a timestamp of 0
+ */
+static void
+lcp_rtt_update_buffer (unsigned long rtt)
+{
+    volatile u_int32_t *const ring_buffer = lcp_rtt_buffer
+       + LCP_RTT_HEADER_LENGTH;
+    unsigned int next_entry, lost;
+
+    /* choose the next entry where the data will be stored */
+    if (ntohl(lcp_rtt_buffer[2]) >= (LCP_RTT_ELEMENTS - 1) * 2)
+       next_entry = 0;                         /* go back to the beginning */
+    else
+       next_entry = ntohl(lcp_rtt_buffer[2]) + 2;      /* use the next one */
+
+    /* update the data element */
+    /* storing the timestamp in an *unsigned* long allows dates up to 2106 */
+    ring_buffer[next_entry] = htonl((u_int32_t) time(NULL));
+    lost = lcp_echos_pending - 1;
+    if (lost > 0xFF)
+       lost = 0xFF;            /* truncate the lost packets count to 256 */
+    if (rtt > 0xFFFFFF)
+       rtt = 0xFFFFFF;         /* truncate the RTT to 16777216 */
+    /* use bits 24-31 for the lost packets count and bits 0-23 for the RTT */
+    ring_buffer[next_entry + 1] = htonl((u_int32_t) ((lost << 24) + rtt));
+
+    /* update the pointer to the (just updated) most current data element */
+    lcp_rtt_buffer[2] = htonl(next_entry);
+
+    /* In theory, CPUs implementing a weakly-consistent memory model do not
+     * guarantee that these three memory store operations to the buffer will
+     * be seen in the same order by the reader process.
+     * This means that a process reading the file could see the index
+     * having been updated before the element that the index points to had
+     * been written.
+     * But in practice we expect that the read(2) system call used by
+     * consumers processes is atomic with respect to the following msync(2)
+     * call, so we ignore the issue.
+     */
+
+    if (msync(lcp_rtt_buffer, LCP_RTT_FILE_SIZE, MS_ASYNC) < 0)
+       error("msync() for %s failed: %m", lcp_rtt_file);
+}
+
 /*
  * LcpEchoReply - LCP has received a reply to the echo
  */
@@ -2246,6 +2332,30 @@ lcp_received_echo_reply (fsm *f, int id, u_char *inp, int len)
        return;
     }
 
+    if (lcp_rtt_file_fd && len >= 16) {
+       long lcp_rtt_magic;
+
+       /*
+        * If the magic word is found at the beginning of the data section
+        * of the frame then read the timestamp which follows and subtract
+        * it from the current time to compute the round trip time.
+        */
+       GETLONG(lcp_rtt_magic, inp);
+       if (lcp_rtt_magic == LCP_RTT_MAGIC) {
+           struct timespec ts;
+           unsigned long req_sec, req_nsec, rtt;
+
+           clock_gettime(CLOCK_MONOTONIC, &ts);
+           GETLONG(req_sec, inp);
+           GETLONG(req_nsec, inp);
+           /* compute the RTT in microseconds */
+           rtt = (ts.tv_sec - req_sec) * 1000000
+               + (ts.tv_nsec / 1000 - req_nsec / 1000);
+           /* log the RTT */
+           lcp_rtt_update_buffer(rtt);
+       }
+    }
+
     /* Reset the number of outstanding echo frames */
     lcp_echos_pending = 0;
 }
@@ -2258,7 +2368,7 @@ static void
 LcpSendEchoRequest (fsm *f)
 {
     u_int32_t lcp_magic;
-    u_char pkt[4], *pktp;
+    u_char pkt[16], *pktp;
 
     /*
      * Detect the failure of the peer at this point.
@@ -2293,11 +2403,68 @@ LcpSendEchoRequest (fsm *f)
         lcp_magic = lcp_gotoptions[f->unit].magicnumber;
        pktp = pkt;
        PUTLONG(lcp_magic, pktp);
+
+       /* Put a timestamp in the data section of the frame */
+       if (lcp_rtt_file_fd) {
+           struct timespec ts;
+
+           PUTLONG(LCP_RTT_MAGIC, pktp);
+           clock_gettime(CLOCK_MONOTONIC, &ts);
+           PUTLONG((u_int32_t)ts.tv_sec, pktp);
+           PUTLONG((u_int32_t)ts.tv_nsec, pktp);
+       }
+
         fsm_sdata(f, ECHOREQ, lcp_echo_number++ & 0xFF, pkt, pktp - pkt);
        ++lcp_echos_pending;
     }
 }
 
+static void
+lcp_rtt_open_file (void)
+{
+    if (!lcp_rtt_file)
+       return;
+
+    lcp_rtt_file_fd = open(lcp_rtt_file, O_RDWR | O_CREAT, 0644);
+    if (lcp_rtt_file_fd < 0) {
+       error("Can't open the RTT log file %s: %m", lcp_rtt_file);
+       lcp_rtt_file_fd = 0;
+       return;
+    }
+
+    if (ftruncate(lcp_rtt_file_fd, LCP_RTT_FILE_SIZE) < 0)
+       fatal("ftruncate() of %s failed: %m", lcp_rtt_file);
+    lcp_rtt_buffer = mmap(0, LCP_RTT_FILE_SIZE, PROT_READ | PROT_WRITE,
+           MAP_SHARED, lcp_rtt_file_fd, 0);
+    if (lcp_rtt_buffer == MAP_FAILED)
+       fatal("mmap() of %s failed: %m", lcp_rtt_file);
+
+    /* initialize the ring buffer */
+    if (lcp_rtt_buffer[0] != htonl(LCP_RTT_MAGIC)) {
+       memset(lcp_rtt_buffer, 0, LCP_RTT_FILE_SIZE);
+       lcp_rtt_buffer[0] = htonl(LCP_RTT_MAGIC);
+    }
+
+    lcp_rtt_buffer[3] = htonl(lcp_echo_interval);
+    lcp_rtt_buffer[1] = htonl(1); /* status: LCP up, file opened */
+}
+
+static void
+lcp_rtt_close_file (void)
+{
+    if (!lcp_rtt_file_fd)
+       return;
+
+    lcp_rtt_buffer[1] = htonl(0); /* status: LCP down, file closed */
+
+    if (munmap(lcp_rtt_buffer, LCP_RTT_FILE_SIZE) < 0)
+       error("munmap() of %s failed: %m", lcp_rtt_file);
+    if (close(lcp_rtt_file_fd) < 0)
+       error("close() of %s failed: %m", lcp_rtt_file);
+    lcp_rtt_buffer = NULL;
+    lcp_rtt_file_fd = 0;
+}
+
 /*
  * lcp_echo_lowerup - Start the timer for the LCP frame
  */
@@ -2311,6 +2478,9 @@ lcp_echo_lowerup (int unit)
     lcp_echos_pending      = 0;
     lcp_echo_number        = 0;
     lcp_echo_timer_running = 0;
+
+    /* Open the file where the LCP RTT data will be logged */
+    lcp_rtt_open_file();
   
     /* If a timeout interval is specified then start the timer */
     if (lcp_echo_interval != 0)
@@ -2330,4 +2500,7 @@ lcp_echo_lowerdown (int unit)
         UNTIMEOUT (LcpEchoTimeout, f);
         lcp_echo_timer_running = 0;
     }
+
+    /* Close the file containing the LCP RTT data */
+    lcp_rtt_close_file();
 }
index 4bac20aa7ac2aab3df84a8b727d490309dd680cb..6c2de4ceb69dd749abd6ca212cf9fd9ab23a5348 100644 (file)
@@ -637,6 +637,10 @@ Set the maximum number of LCP terminate-request transmissions to
 Set the LCP restart interval (retransmission timeout) to \fIn\fR
 seconds (default 3).
 .TP
+.B lcp\-rtt\-file \fIfilename
+Sets the file where the round-trip time (RTT) of LCP echo-request frames
+will be logged.
+.TP
 .B linkname \fIname\fR
 Sets the logical name of the link to \fIname\fR.  Pppd will create a
 file named \fBppp\-\fIname\fB.pid\fR in /var/run (or /etc/ppp on some
diff --git a/scripts/lcp_rtt_dump b/scripts/lcp_rtt_dump
new file mode 100755 (executable)
index 0000000..7898f08
--- /dev/null
@@ -0,0 +1,81 @@
+#!/usr/bin/perl
+# vim: shiftwidth=4 tabstop=4
+#
+# This program dumps to standard output the content of the file written
+# by pppd's lcp-rtt-file configuration option.
+#
+# Copyright (C) Marco d'Itri <md@linux.it>
+#
+# 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.
+
+use v5.14;
+use warnings;
+use autodie;
+
+use POSIX qw(strftime);
+
+{
+       my $data = read_data($ARGV[0] || '/run/ppp-rtt.data');
+       die "The data file is invalid!\n" if not $data;
+       dump_data($data);
+}
+
+sub dump_data {
+       my ($s) = @_;
+
+       say "status:   $s->{status}";
+       say "interval: $s->{echo_interval}";
+       say "position: $s->{position}";
+       say 'elements: ' . scalar(@{ $s->{data} });
+       say '';
+
+       foreach (my $i= 0; $i < @{ $s->{data} }; $i++) {
+               my $date = strftime('%F %T', localtime($s->{data}->[$i]->[0]));
+               print "$i\t$date\t$s->{data}->[$i]->[1]\t$s->{data}->[$i]->[2]\n";
+       }
+}
+
+sub read_data {
+       my ($file) = @_;
+
+       my $data;
+       open(my $fh, '<', $file);
+       binmode($fh);
+       my $bytes_read;
+       do {
+               $bytes_read = sysread($fh, $data, 8192, length($data));
+       } while ($bytes_read == 8192);
+       close($fh);
+
+       my ($magic, $status, $position, $echo_interval, $rest)
+               = unpack('NNNN a*', $data);
+       return undef if $magic != 0x19450425;
+
+       # the position is relative to the C array, not to the logical entries
+       $position /= 2;
+
+       my @rawdata = unpack('(N C a3)*', $rest);
+       my @data;
+       while (my ($time, $loss, $rtt) = splice(@rawdata, 0, 3)) {
+               push(@data, [ $time, unpack('N', "\000$rtt"), $loss ]);
+       }
+
+       if (0) {
+       @data =
+               # skip any "empty" (null) entries
+               grep { $_->[0] }
+               # rearrange the list in chronological order
+               (@data[$position+1 .. $#data], @data[0 .. $position]);
+       }
+
+       return {
+               status                  => $status,
+               echo_interval   => $echo_interval,
+               position                => $position,
+               data                    => \@data,
+       };
+}
+
diff --git a/scripts/lcp_rtt_exporter b/scripts/lcp_rtt_exporter
new file mode 100644 (file)
index 0000000..6fab745
--- /dev/null
@@ -0,0 +1,108 @@
+#!/usr/bin/perl
+# vim: shiftwidth=4 tabstop=4
+#
+# This CGI program is a Prometheus exporter for pppd's lcp-rtt-file feature.
+#
+# Copyright (C) Marco d'Itri <md@linux.it>
+#
+# 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.
+
+use v5.14;
+use warnings;
+use autodie;
+
+use List::Util qw(sum max min);
+
+{
+       my $data = read_data('/run/ppp-rtt.data');
+       my $stats = compute_statistics($data, 60);
+
+       my $s = metrics($stats);
+
+       print "Content-type: text/plain\n\n$s";
+       exit;
+}
+
+sub metrics {
+       my ($stats) = @_;
+
+       my $s = <<END;
+# TYPE lcp_rtt_status gauge
+# HELP LCP RTT status
+lcp_rtt_status $stats->{status}
+END
+       foreach (qw(average min max loss)) {
+               next if not exists $stats->{$_};
+               $s .= <<END;
+# TYPE lcp_rtt_$_ gauge
+# HELP LCP RTT $_
+lcp_rtt_$_ $stats->{$_}
+END
+       }
+
+       return $s;
+}
+
+sub compute_statistics {
+       my ($data, $length) = @_;
+
+       my $cutoff = time() - $length;
+       my @e = grep { $_->[0] >= $cutoff } @{ $data->{data} };
+       return { status => -1 } if not @e; # no data
+
+       my $average = (sum map { $_->[1] } @e) / scalar(@e);
+       my $min = min map { $_->[1] } @e;
+       my $max = max map { $_->[1] } @e;
+       my $loss = sum map { $_->[2] } @e;
+
+       return {
+               status  => $data->{status},
+               average => $average,
+               min             => $min,
+               max             => $max,
+               loss    => $loss,
+       };
+}
+
+sub read_data {
+       my ($file) = @_;
+
+       my $data;
+       open(my $fh, '<', $file);
+       binmode($fh);
+       my $bytes_read;
+       do {
+               $bytes_read = sysread($fh, $data, 8192, length($data));
+       } while ($bytes_read == 8192);
+       close($fh);
+
+       my ($magic, $status, $position, $echo_interval, $rest)
+               = unpack('NNNN a*', $data);
+       return undef if $magic != 0x19450425;
+
+       # the position is relative to the C array, not to the logical entries
+       $position /= 2;
+
+       my @rawdata = unpack('(N C a3)*', $rest);
+       my @data;
+       while (my ($time, $loss, $rtt) = splice(@rawdata, 0, 3)) {
+               push(@data, [ $time, unpack('N', "\000$rtt"), $loss ]);
+       }
+
+       @data =
+               # skip any "empty" (null) entries
+               grep { $_->[0] }
+               # rearrange the list in chronological order
+               (@data[$position+1 .. $#data], @data[0 .. $position]);
+
+       return {
+               status                  => $status,
+               echo_interval   => $echo_interval,
+               position                => $position,
+               data                    => \@data,
+       };
+}
+