netstacklat: Exclude TCP reads for HOL blocked segments

The 'tcp-socket-read' currently reports the latency for the skb
containing the last TCP segment read from the socket. However, this
segment might have been head of line (HOL) blocked by a previous
segment missing. In this case, netstacklat's reported latency will
include HOL blocking periods that is dependent on external
factors (such as network packet loss, and network latency impacts
retransmission time). As netstacklat is primarily intended to identify
issues within the local host (in the network stack or receiving
applications), by default filter out any socket reads were the last
read SKB might have experienced HOL-blocking.

Add the new -y/--include-tcp-hol-delay option to retain the old
behavior of reporting latency for all reads, including those that are
HOL-blocked. This may be useful in some scenarios when you still want
to be aware of latency issues caused by HOL-blocking, even though it
is caused by external components. For example, in a data center
context were you have full control over the network, it may still be
relevant to monitor HOL-based caused by the network.

To exclude HOL-blocked reads, detect if any new ooo-segments have
arrived by checking for differences in the number of ooo-packets in
tcp_sock->rcv_ooopack. If any new ooo-segments have arrived, exclude
the latency sample from the current read and set a limit for the next
safe sequence number to read where the current ooo-packets must have
been passed so segments can no longer be HOL-blocked. If there are
skbs in the ooo-queue, set the limit to the end of the
ooo-queue. Otherwise, set the limit to the current rcv_nxt (as if the
ooo-queue is empty the detected ooo-segments must already have been
merged into the receive queue and rcv_nxt must have advanced past
them). If the read is past the safe sequence limit and no new
ooo-segments have arrived, it's safe to start including the latency
samples again.

For sockets were some ooo-segments have been observed, keep the
ooo-range state in socket storage (BPF_MAP_TYPE_SK_STORAGE). Skip
protecting this state with a spin-lock, as it should only be
concurrently accessed if there are concurrent reads on the same TCP
socket, which is assumed to be very rare as applications attempting
that cannot know which part of the data each of their concurrent reads
will get.

There are some scenarios that may cause this ooo-filtering to fail.
- If multiple reads are done to the socket concurrently, we may not
  correctly track the last read byte. The kernel does not keep a lock
  on the TCP socket at the time our hooked function
  tcp_recv_timestamp() runs. If two reads are done in parallel, it's
  therefore possible that for both reads we will check the last read
  byte (tcp_sock.copied_seq) after the second read has updated it. We
  may then incorrectly conclude that the first read was ahead of the
  ooo-range when it was not, and record its latency when we should
  have excluded it. In practice I belive this issue should be quite
  rare, as most applications will probably not attempt to perform
  multiple concurrent reads to a single connected TCP socket in
  parallel (as then you cannot know which part of the payload the
  parallel reads will return).

- As tcp_recv_timestamp() runs outside of the socket lock, the various
  state members we access may concurrently be updated as we're
  attempting to read them. An especially problematic one is
  tcp_sock.ooo_last_skb, which keeps a pointer to an SKB that is only
  valid while the ooo-queue is non-empty. It is possible that between
  our check for if the ooo-queue is non-empty and following the
  ooo_last_skb pointer, the ooo-queue is cleared and the ooo_last_skb
  pointer may end up pointing towards a freed SKB. If the socket
  members we access are updated before or while we read them, it can
  break the filtering in numerous ways, e.g. result in includes
  samples that should have been excluded (due to e.g. copied_seq being
  updated before our read) or excluding a large amount of valid
  samples (due to e.g. setting a sequence limit based on garbage in a
  freed SKB).

Signed-off-by: Simon Sundberg <[email protected]>
Signed-off-by: Jesper Dangaard Brouer <[email protected]>

Author: simosund

examples/netstacklat.bpf.c

@@ -21,6 +21,10 @@
 
 #define READ_ONCE(x) (*(volatile typeof(x) *)&(x))
 
+// Mimic macros from /include/net/tcp.h
+#define tcp_sk(ptr) container_of(ptr, struct tcp_sock, inet_conn.icsk_inet.sk)
+#define TCP_SKB_CB(__skb)	((struct tcp_skb_cb *)&((__skb)->cb[0]))
+
 char LICENSE[] SEC("license") = "GPL";
 
 /* The ebpf_exporter variant of netstacklat is not runtime configurable at
@@ -37,6 +41,7 @@ const struct netstacklat_bpf_config user_config = {
 	.filter_cgroup = true,
 	.groupby_ifindex = false, /* If true also define CONFIG_GROUPBY_IFINDEX */
 	.groupby_cgroup = true,
+	.include_hol_blocked = false,
 };
 
 /* This provide easy way compile-time to disable some hooks */
@@ -86,6 +91,13 @@ struct sk_buff___old {
 #err "Please update N_HOOKS"
 #endif
 
+struct tcp_sock_ooo_range {
+	u32 prev_n_ooopkts;
+	u32 ooo_seq_end;
+	/* indicates if ooo_seq_end is still valid (as 0 can be valid seq) */
+	bool active;
+};
+
 struct {
 	__uint(type, BPF_MAP_TYPE_PERCPU_HASH);
 	__uint(max_entries, HIST_NBUCKETS * N_HOOKS * N_CGROUPS * N_IFACES);
@@ -151,6 +163,22 @@ static ktime_t time_since(ktime_t tstamp)
 	return (now - tstamp) / LATENCY_SCALE;
 }
 
+/*
+ * Is a < b considering u32 wrap around?
+ * Based on the before() function in /include/net/tcp.h
+ */
+static bool u32_lt(u32 a, u32 b)
+{
+	return (s32)(a - b) < 0;
+}
+
+struct {
+	__uint(type, BPF_MAP_TYPE_SK_STORAGE);
+	__uint(map_flags, BPF_F_NO_PREALLOC);
+	__type(key, int);
+	__type(value, struct tcp_sock_ooo_range);
+} netstack_tcp_ooo_range SEC(".maps");
+
 /* Determine if ebpf_exporter macro or local C implementation is used */
 #define CONFIG_MAP_MACROS	1
 #ifdef  CONFIG_MAP_MACROS
@@ -476,6 +504,102 @@ static __always_inline bool filter_socket(struct sock *sk, struct sk_buff *skb,
 }
 #endif
 
+static int current_max_possible_ooo_seq(struct tcp_sock *tp, u32 *seq)
+{
+	struct tcp_skb_cb cb;
+	u32 max_seq = 0;
+	int err = 0;
+
+	if (BPF_CORE_READ(tp, out_of_order_queue.rb_node) == NULL) {
+		/* No ooo-segments currently in ooo-queue
+		 * Any ooo-segments must already have been merged to the
+		 * receive queue. Current rcv_nxt must therefore be ahead
+		 * of all ooo-segments that have arrived until now.
+		 */
+		err = bpf_core_read(&max_seq, sizeof(max_seq), &tp->rcv_nxt);
+		if (err)
+			bpf_printk("failed to read tcp_sock->rcv_nxt, err=%d",
+				   err);
+	} else {
+		/*
+		 * Some ooo-segments currently in ooo-queue
+		 * Max out-of-order seq is given by the seq_end of the tail
+		 * skb in the ooo-queue.
+		 */
+		err = BPF_CORE_READ_INTO(&cb, tp, ooo_last_skb, cb);
+		if (err)
+			bpf_printk(
+				"failed to read tcp_sock->ooo_last_skb->cb, err=%d",
+				err);
+		max_seq = cb.end_seq;
+	}
+
+	*seq = max_seq;
+	return err;
+}
+
+static bool tcp_read_in_ooo_range(struct tcp_sock *tp,
+				  struct tcp_sock_ooo_range *ooo_range)
+{
+	u32 read_seq;
+	int err;
+
+	if (!ooo_range->active)
+		return false;
+
+	err = bpf_core_read(&read_seq, sizeof(read_seq), &tp->copied_seq);
+	if (err) {
+		bpf_printk("failed to read tcp_sock->copied_seq, err=%d", err);
+		return true; // Assume we may be in ooo-range
+	}
+
+	if (u32_lt(ooo_range->ooo_seq_end, read_seq)) {
+		ooo_range->active = false;
+		return false;
+	} else {
+		return true;
+	}
+}
+
+static bool tcp_read_maybe_holblocked(struct sock *sk)
+{
+	struct tcp_sock_ooo_range *ooo_range;
+	struct tcp_sock *tp = tcp_sk(sk);
+	u32 n_ooopkts, nxt_seq;
+	int err;
+
+	err = bpf_core_read(&n_ooopkts, sizeof(n_ooopkts), &tp->rcv_ooopack);
+	if (err) {
+		bpf_printk("failed to read tcp_sock->rcv_ooopack, err=%d\n",
+			   err);
+		return true; // Assume we may be in ooo-range
+	}
+
+	if (n_ooopkts == 0)
+		return false;
+
+	ooo_range = bpf_sk_storage_get(&netstack_tcp_ooo_range, sk, NULL,
+				       BPF_SK_STORAGE_GET_F_CREATE);
+	if (!ooo_range) {
+		bpf_printk(
+			"failed getting ooo-range socket storage for tcp socket");
+		return true; // Assume we may be in ooo-range
+	}
+
+	// Increase in ooo-packets since last - figure out next safe seq
+	if (n_ooopkts > ooo_range->prev_n_ooopkts) {
+		ooo_range->prev_n_ooopkts = n_ooopkts;
+		err = current_max_possible_ooo_seq(tp, &nxt_seq);
+		if (!err) {
+			ooo_range->ooo_seq_end = nxt_seq;
+			ooo_range->active = true;
+		}
+		return true;
+	}
+
+	return tcp_read_in_ooo_range(tp, ooo_range);
+}
+
 static void record_socket_latency(struct sock *sk, struct sk_buff *skb,
 				  ktime_t tstamp, enum netstacklat_hook hook,
 				  u64 cgroup_id)
@@ -590,6 +714,10 @@ int BPF_PROG(netstacklat_tcp_recv_timestamp, void *msg, struct sock *sk,
 		return 0;
 
 	struct timespec64 *ts = &tss->ts[0];
+
+	if (!user_config.include_hol_blocked && tcp_read_maybe_holblocked(sk))
+		return 0;
+
 	record_socket_latency(sk, NULL,
 			      (ktime_t)ts->tv_sec * NS_PER_S + ts->tv_nsec,
 			      hook, cgroup_id);

examples/netstacklat.h

@@ -87,6 +87,7 @@ struct netstacklat_bpf_config {
 	bool filter_cgroup;
 	bool groupby_ifindex;
 	bool groupby_cgroup;
+	bool include_hol_blocked;
 };
 
 #endif