Skip to content

Commit

Permalink
Merge pull request #422 from rfc1036/lcp-rtt
Browse files Browse the repository at this point in the history
Implement logging the LCP Round Trip Time
  • Loading branch information
paulusmack authored Sep 30, 2023
2 parents ee10701 + d7f54a4 commit edc1926
Show file tree
Hide file tree
Showing 4 changed files with 367 additions and 1 deletion.
175 changes: 174 additions & 1 deletion pppd/lcp.c
Original file line number Diff line number Diff line change
Expand Up @@ -47,6 +47,11 @@
#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"
Expand All @@ -67,12 +72,22 @@

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 */

Expand Down Expand Up @@ -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,
Expand Down Expand Up @@ -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 */

Expand Down Expand Up @@ -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
*/
Expand All @@ -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;
}
Expand All @@ -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.
Expand Down Expand Up @@ -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
*/
Expand All @@ -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)
Expand All @@ -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();
}
4 changes: 4 additions & 0 deletions pppd/pppd.8
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down
81 changes: 81 additions & 0 deletions scripts/lcp_rtt_dump
Original file line number Diff line number Diff line change
@@ -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 <[email protected]>
#
# 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,
};
}

Loading

0 comments on commit edc1926

Please sign in to comment.