pping: Do both timestamping and matching on ingress and egress

Perform both timestamping and matching on both ingress and egress
hooks. This makes it more similar to Kathie's pping, allowing the tool
to capture RTTs in both directions when deployed on just a single
interface.

Like Kathie's pping, by default filter out RTTs for packets going to
the local machine (will only include local processing delays). This
behavior can be disabled by passing the -l/--include-local option.

As packets that are timestamped on ingress and matched on egress will
include the local machines processing delay, add the "match_on_egress"
member to the JSON output that can be used to differentiate between
RTTs that include the local processing delay, and those which don't.

Finally, report the source and destination addresses from the perspective
of the reply packet, rather than the timestamped packet, to be
consistent with Kathie's pping.

Overall, refactor large parts of pping_kern to allow both timestamping
and matching, as well as updating both the flow and reverse flow and
handle flow-events related to them, in one go. Also update README to
reflect changes.

Signed-off-by: Simon Sundberg <simon.sundberg@kau.se>

Author: simosund

pping/README.md

@@ -13,20 +13,21 @@ spinbit and DNS queries. See the [TODO-list](./TODO.md) for more potential
 features (which may or may not ever get implemented).
 
 The fundamental logic of pping is to timestamp a pseudo-unique identifier for
-outgoing packets, and then look for matches in the incoming packets. If a match
-is found, the RTT is simply calculated as the time difference between the
-current time and the stored timestamp.
+packets, and then look for matches in the reply packets. If a match is found,
+the RTT is simply calculated as the time difference between the current time and
+the stored timestamp.
 
 This tool, just as Kathie's original pping implementation, uses TCP timestamps
-as identifiers for TCP traffic. For outgoing packets, the TSval (which is a
-timestamp in and off itself) is timestamped. Incoming packets are then parsed
-for the TSecr, which are the echoed TSval values from the receiver. The TCP
-timestamps are not necessarily unique for every packet (they have a limited
-update frequency, appears to be 1000 Hz for modern Linux systems), so only the
-first instance of an identifier is timestamped, and matched against the first
-incoming packet with the identifier. The mechanism to ensure only the first
-packet is timestamped and matched differs from the one in Kathie's pping, and is
-further described in [SAMPLING_DESIGN](./SAMPLING_DESIGN.md).
+as identifiers for TCP traffic. The TSval (which is a timestamp in and off
+itself) is used as an identifier and timestamped. Reply packets in the reverse
+flow are then parsed for the TSecr, which are the echoed TSval values from the
+receiver. The TCP timestamps are not necessarily unique for every packet (they
+have a limited update frequency, appears to be 1000 Hz for modern Linux
+systems), so only the first instance of an identifier is timestamped, and
+matched against the first incoming packet with a matching reply identifier. The
+mechanism to ensure only the first packet is timestamped and matched differs
+from the one in Kathie's pping, and is further described in
+[SAMPLING_DESIGN](./SAMPLING_DESIGN.md).
 
 For ICMP echo, it uses the echo identifier as port numbers, and echo sequence
 number as identifer to match against. Linux systems will typically use different
@@ -48,7 +49,7 @@ single line per event.
 
 An example of the format is provided below:
 ```shell
-16:00:46.142279766 TCP 10.11.1.1:5201+10.11.1.2:59528 opening due to SYN-ACK from src
+16:00:46.142279766 TCP 10.11.1.1:5201+10.11.1.2:59528 opening due to SYN-ACK from dest
 16:00:46.147705205 5.425439 ms 5.425439 ms TCP 10.11.1.1:5201+10.11.1.2:59528
 16:00:47.148905125 5.261430 ms 5.261430 ms TCP 10.11.1.1:5201+10.11.1.2:59528
 16:00:48.151666385 5.972284 ms 5.261430 ms TCP 10.11.1.1:5201+10.11.1.2:59528
@@ -96,7 +97,7 @@ An example of a (pretty-printed) flow-event is provided below:
     "protocol": "TCP",
     "flow_event": "opening",
     "reason": "SYN-ACK",
-    "triggered_by": "src"
+    "triggered_by": "dest"
 }
 ```
 
@@ -114,7 +115,8 @@ An example of a (pretty-printed) RTT-even is provided below:
     "sent_packets": 9393,
     "sent_bytes": 492457296,
     "rec_packets": 5922,
-    "rec_bytes": 37
+    "rec_bytes": 37,
+    "match_on_egress": false
 }
 ```
 
@@ -123,36 +125,33 @@ An example of a (pretty-printed) RTT-even is provided below:
 
 ### Files:
 - **pping.c:** Userspace program that loads and attaches the BPF programs, pulls
-  the perf-buffer `rtt_events` to print out RTT messages and periodically cleans
+  the perf-buffer `events` to print out RTT messages and periodically cleans
   up the hash-maps from old entries. Also passes user options to the BPF
   programs by setting a "global variable" (stored in the programs .rodata
   section).
-- **pping_kern.c:** Contains the BPF programs that are loaded on tc (egress) and
-  XDP (ingress), as well as several common functions, a global constant `config`
-  (set from userspace) and map definitions. The tc program `pping_egress()`
-  parses outgoing packets for identifiers. If an identifier is found and the
-  sampling strategy allows it, a timestamp for the packet is created in
-  `packet_ts`. The XDP program `pping_ingress()` parses incomming packets for an
-  identifier. If found, it looks up the `packet_ts` map for a match on the
-  reverse flow (to match source/dest on egress). If there is a match, it
-  calculates the RTT from the stored timestamp and deletes the entry. The
-  calculated RTT (together with the flow-tuple) is pushed to the perf-buffer
-  `events`. Both `pping_egress()` and `pping_ingress` can also push flow-events
-  to the `events` buffer.
+- **pping_kern.c:** Contains the BPF programs that are loaded on egress (tc) and
+  ingress (XDP or tc), as well as several common functions, a global constant
+  `config` (set from userspace) and map definitions. Essentially the same pping
+  program is loaded on both ingress and egress. All packets are parsed for both
+  an identifier that can be used to create a timestamp entry `packet_ts`, and a
+  reply identifier that can be used to match the packet with a previously
+  timestamped one in the reverse flow. If a match is found, an RTT is calculated
+  and an RTT-event is pushed to userspace through the perf-buffer `events`. For
+  each packet with a valid identifier, the program also keeps track of and
+  updates the state flow and reverse flow, stored in the `flow_state` map.
 - **pping.h:** Common header file included by `pping.c` and
   `pping_kern.c`. Contains some common structs used by both (are part of the
   maps).
 
 ### BPF Maps:
 - **flow_state:** A hash-map storing some basic state for each flow, such as the
   last seen identifier for the flow and when the last timestamp entry for the
-  flow was created. Entries are created by `pping_egress()`, and can be updated
-  or deleted by both `pping_egress()` and `pping_ingress()`. Leftover entries
-  are eventually removed by `pping.c`.
+  flow was created. Entries are created, updated and deleted by the BPF pping
+  programs. Leftover entries are eventually removed by userspace (`pping.c`).
 - **packet_ts:** A hash-map storing a timestamp for a specific packet
-  identifier. Entries are created by `pping_egress()` and removed by
-  `pping_ingress()` if a match is found. Leftover entries are eventually removed
-  by `pping.c`.
+  identifier. Entries are created by the BPF pping program if a valid identifier
+  is found, and removed if a match is found. Leftover entries are eventually
+  removed by userspace (`pping.c`).
 - **events:** A perf-buffer used by the BPF programs to push flow or RTT events
   to `pping.c`, which continuously polls the map the prints them out.
 
@@ -222,9 +221,9 @@ additional map space and report some additional RTT(s) more than expected
 (however the reported RTTs should still be correct).
 
 If the packets have the same identifier, they must first have managed to bypass
-the previous check for unique identifiers (see [previous point](#Tracking last
-seen identifier)), and only one of them will be able to successfully store a
-timestamp entry.
+the previous check for unique identifiers (see [previous
+point](#tracking-last-seen-identifier)), and only one of them will be able to
+successfully store a timestamp entry.
 
 #### Matching against stored timestamps
 The XDP/ingress program could potentially match multiple concurrent packets with
@@ -246,8 +245,8 @@ if this is the lowest RTT seen so far for the flow. If multiple RTTs are
 calculated concurrently, then several could pass this check concurrently and
 there may be a lost update. It should only be possible for multiple RTTs to be
 calculated concurrently in case either the [timestamp rate-limit was
-bypassed](#Rate-limiting new timestamps) or [multiple packets managed to match
-against the same timestamp](#Matching against stored timestamps).
+bypassed](#rate-limiting-new-timestamps) or [multiple packets managed to match
+against the same timestamp](#matching-against-stored-timestamps).
 
 It's worth noting that with sampling the reported minimum-RTT is only an
 estimate anyways (may never calculate RTT for packet with the true minimum

pping/eBPF_pping_design.png

@@ -15,11 +15,8 @@ static const char *__doc__ =
 #include <unistd.h>
 #include <getopt.h>
 #include <stdbool.h>
-#include <limits.h>
 #include <signal.h> // For detecting Ctrl-C
 #include <sys/resource.h> // For setting rlmit
-#include <sys/wait.h>
-#include <sys/stat.h>
 #include <time.h>
 #include <pthread.h>
 
@@ -108,6 +105,7 @@ static const struct option long_options[] = {
 	{ "ingress-hook",     required_argument, NULL, 'I' }, // Use tc or XDP as ingress hook
 	{ "tcp",              no_argument,       NULL, 'T' }, // Calculate and report RTTs for TCP traffic (with TCP timestamps)
 	{ "icmp",             no_argument,       NULL, 'C' }, // Calculate and report RTTs for ICMP echo-reply traffic
+	{ "include-local",    no_argument,       NULL, 'l' }, // Also report "internal" RTTs
 	{ 0, 0, NULL, 0 }
 };
 
@@ -172,11 +170,12 @@ static int parse_arguments(int argc, char *argv[], struct pping_config *config)
 	double rate_limit_ms, cleanup_interval_s, rtt_rate;
 
 	config->ifindex = 0;
+	config->bpf_config.localfilt = true;
 	config->force = false;
 	config->bpf_config.track_tcp = false;
 	config->bpf_config.track_icmp = false;
 
-	while ((opt = getopt_long(argc, argv, "hfTCi:r:R:t:c:F:I:", long_options,
+	while ((opt = getopt_long(argc, argv, "hflTCi:r:R:t:c:F:I:", long_options,
 				  NULL)) != -1) {
 		switch (opt) {
 		case 'i':
@@ -257,6 +256,9 @@ static int parse_arguments(int argc, char *argv[], struct pping_config *config)
 				return -EINVAL;
 			}
 			break;
+		case 'l':
+			config->bpf_config.localfilt = false;
+			break;
 		case 'f':
 			config->force = true;
 			config->xdp_flags &= ~XDP_FLAGS_UPDATE_IF_NOEXIST;
@@ -504,9 +506,9 @@ static bool flow_timeout(void *key_ptr, void *val_ptr, __u64 now)
 		if (print_event_func) {
 			fe.event_type = EVENT_TYPE_FLOW;
 			fe.timestamp = now;
-			fe.flow = *(struct network_tuple *)key_ptr;
-			fe.event_info.event = FLOW_EVENT_CLOSING;
-			fe.event_info.reason = EVENT_REASON_FLOW_TIMEOUT;
+			reverse_flow(&fe.flow, key_ptr);
+			fe.flow_event_type = FLOW_EVENT_CLOSING;
+			fe.reason = EVENT_REASON_FLOW_TIMEOUT;
 			fe.source = EVENT_SOURCE_USERSPACE;
 			print_event_func(NULL, 0, &fe, sizeof(fe));
 		}
@@ -657,6 +659,7 @@ static const char *flowevent_to_str(enum flow_event_type fe)
 	case FLOW_EVENT_OPENING:
 		return "opening";
 	case FLOW_EVENT_CLOSING:
+	case FLOW_EVENT_CLOSING_BOTH:
 		return "closing";
 	default:
 		return "unknown";
@@ -674,8 +677,6 @@ static const char *eventreason_to_str(enum flow_event_reason er)
 		return "first observed packet";
 	case EVENT_REASON_FIN:
 		return "FIN";
-	case EVENT_REASON_FIN_ACK:
-		return "FIN-ACK";
 	case EVENT_REASON_RST:
 		return "RST";
 	case EVENT_REASON_FLOW_TIMEOUT:
@@ -688,9 +689,9 @@ static const char *eventreason_to_str(enum flow_event_reason er)
 static const char *eventsource_to_str(enum flow_event_source es)
 {
 	switch (es) {
-	case EVENT_SOURCE_EGRESS:
+	case EVENT_SOURCE_PKT_SRC:
 		return "src";
-	case EVENT_SOURCE_INGRESS:
+	case EVENT_SOURCE_PKT_DEST:
 		return "dest";
 	case EVENT_SOURCE_USERSPACE:
 		return "userspace-cleanup";
@@ -740,8 +741,8 @@ static void print_event_standard(void *ctx, int cpu, void *data,
 		printf(" %s ", proto_to_str(e->rtt_event.flow.proto));
 		print_flow_ppvizformat(stdout, &e->flow_event.flow);
 		printf(" %s due to %s from %s\n",
-		       flowevent_to_str(e->flow_event.event_info.event),
-		       eventreason_to_str(e->flow_event.event_info.reason),
+		       flowevent_to_str(e->flow_event.flow_event_type),
+		       eventreason_to_str(e->flow_event.reason),
 		       eventsource_to_str(e->flow_event.source));
 	}
 }
@@ -790,15 +791,16 @@ static void print_rttevent_fields_json(json_writer_t *ctx,
 	jsonw_u64_field(ctx, "sent_bytes", re->sent_bytes);
 	jsonw_u64_field(ctx, "rec_packets", re->rec_pkts);
 	jsonw_u64_field(ctx, "rec_bytes", re->rec_bytes);
+	jsonw_bool_field(ctx, "match_on_egress", re->match_on_egress);
 }
 
 static void print_flowevent_fields_json(json_writer_t *ctx,
 					const struct flow_event *fe)
 {
 	jsonw_string_field(ctx, "flow_event",
-			   flowevent_to_str(fe->event_info.event));
+			   flowevent_to_str(fe->flow_event_type));
 	jsonw_string_field(ctx, "reason",
-			   eventreason_to_str(fe->event_info.reason));
+			   eventreason_to_str(fe->reason));
 	jsonw_string_field(ctx, "triggered_by", eventsource_to_str(fe->source));
 }
 

pping/pping.c

@@ -18,22 +18,22 @@ typedef __u64 fixpoint64;
 enum __attribute__((__packed__)) flow_event_type {
 	FLOW_EVENT_NONE,
 	FLOW_EVENT_OPENING,
-	FLOW_EVENT_CLOSING
+	FLOW_EVENT_CLOSING,
+	FLOW_EVENT_CLOSING_BOTH
 };
 
 enum __attribute__((__packed__)) flow_event_reason {
 	EVENT_REASON_SYN,
 	EVENT_REASON_SYN_ACK,
 	EVENT_REASON_FIRST_OBS_PCKT,
 	EVENT_REASON_FIN,
-	EVENT_REASON_FIN_ACK,
 	EVENT_REASON_RST,
 	EVENT_REASON_FLOW_TIMEOUT
 };
 
 enum __attribute__((__packed__)) flow_event_source {
-	EVENT_SOURCE_EGRESS,
-	EVENT_SOURCE_INGRESS,
+	EVENT_SOURCE_PKT_SRC,
+	EVENT_SOURCE_PKT_DEST,
 	EVENT_SOURCE_USERSPACE
 };
 
@@ -43,7 +43,8 @@ struct bpf_config {
 	bool use_srtt;
 	bool track_tcp;
 	bool track_icmp;
-	__u8 reserved[5];
+	bool localfilt;
+	__u32 reserved;
 };
 
 /*
@@ -108,12 +109,8 @@ struct rtt_event {
 	__u64 sent_bytes;
 	__u64 rec_pkts;
 	__u64 rec_bytes;
-	__u32 reserved;
-};
-
-struct flow_event_info {
-	enum flow_event_type event;
-	enum flow_event_reason reason;
+	bool match_on_egress;
+	__u8 reserved[7];
 };
 
 /*
@@ -126,7 +123,8 @@ struct flow_event {
 	__u64 event_type;
 	__u64 timestamp;
 	struct network_tuple flow;
-	struct flow_event_info event_info;
+	enum flow_event_type flow_event_type;
+	enum flow_event_reason reason;
 	enum flow_event_source source;
 	__u8 reserved;
 };
@@ -137,4 +135,19 @@ union pping_event {
 	struct flow_event flow_event;
 };
 
+/*
+ * Convenience function for getting the corresponding reverse flow.
+ * PPing needs to keep track of flow in both directions, and sometimes
+ * also needs to reverse the flow to report the "correct" (consistent
+ * with Kathie's PPing) src and dest address.
+ */
+static void reverse_flow(struct network_tuple *dest, struct network_tuple *src)
+{
+	dest->ipv = src->ipv;
+	dest->proto = src->proto;
+	dest->saddr = src->daddr;
+	dest->daddr = src->saddr;
+	dest->reserved = 0;
+}
+
 #endif