eBPF sk_skb programs lead to connection issues for Thrift RPCs

132 Views Asked by At

Edit: The service I was using, uses Thrift as the rpc framework. It turns out that Thrift RPCs have a problem with SK_SKB messages. Using the CPP Tutorial from thrift repo also fails when a SK_SKB program is loaded. It fails with a THRIFT_EAGAIN (unavailable resources) error.

  1. Does Thrift not use TCP as the underlying socket connection?
  2. Or is this because of some other contention caused due to eBPF SK_SKB program?

Original Question: I am writing sk_skb programs to read the incoming packets to a cgroup. I already have a sockops program loaded and a SOCKHASH map loaded and pinned to /sys/fs/bpf/sockops. Here is my SK_SKB bpf program:

#include <stdio.h>

#include <linux/bpf.h>
#include <sys/socket.h>

#include <bpf/bpf_helpers.h>

char LICENSE[] SEC("license") = "GPL";

#define MAX_MSG_LEN 256

SEC("sk_skb/stream_parser")
int parse_skb(struct __sk_buff *skb) {
  int err;
  unsigned long len = (long)skb->data_end - (long)skb->data;

  bpf_printk("Message length: %ld %ld", len, skb->len);

  return skb->len;
}

SEC("sk_skb/stream_verdict")
int read_skb(struct __sk_buff *skb) {
  // int err;

  // Retest the length.
  unsigned long len = (long)skb->data_end - (long)skb->data;
  bpf_printk("Message updated length: %ld", len);

  // Bounds check to make verifier happy
  void *data = (void *)(long) skb->data;
  void *data_end = (void *)(long) skb->data_end;
  if (data + MAX_MSG_LEN > data_end) {
    return SK_PASS;
  }

  return SK_PASS;
}

Edit: I replaced the above programs with simple no-op programs that just call bpf_printk() in the the two programs, but the result is still the same.

The above program compiles and loads properly. I use the following userspace loader to attach and load the program:

static const char *__doc__ = "User space program to load bpf program for the fast path\n";

#include <bpf/bpf.h>
#include <bpf/libbpf.h>
#include <errno.h>
#include <fcntl.h>
#include <string.h>
#include <unistd.h>

#include "../common/common_params.h"
#include "../common/common_user_bpf_xdp.h"

const char *pin_dir = "/sys/fs/bpf";

int main(int argc, char **argv) {
  int err, len;
  int prog_fd, sock_map_fd;
  char map_filename[PATH_MAX];
  struct bpf_object *bpf_skb_obj;
  const char *bpf_skb_file = "sk_skb.o";

  // Get fd of the pinned sockops map in pindir/subdir
  len = snprintf(map_filename, PATH_MAX, "%s/%s", pin_dir, "sockops");
  if (len < 0) {
    goto fail;
  }

  sock_map_fd = bpf_obj_get(map_filename);
  if (sock_map_fd < 0) {
    goto fail;
  }

  // Open, load and attach sockops_obj if not already attached
  bpf_skb_obj = bpf_object__open_file(bpf_skb_file, NULL);
  if (libbpf_get_error(bpf_skb_obj)) {
    goto fail;
  }

  // Load the sk_skb program
  err = bpf_object__load(bpf_skb_obj);
  if (err) {
    goto fail;
  }

  // Find the stream_parser program
  struct bpf_program *skb_parser_prog = bpf_object__find_program_by_name(bpf_skb_obj, "parse_skb");
  if (!skb_parser_prog) {
    goto fail;
  }

  // Find the stream_verdict program
  struct bpf_program *skb_verdict_prog = bpf_object__find_program_by_name(bpf_skb_obj, "read_skb");
  if (!skb_verdict_prog) {
    goto fail;
  }

  // Attach the skb_parser program to the map.
  err = bpf_prog_attach(bpf_program__fd(skb_parser_prog), sock_map_fd, BPF_SK_SKB_STREAM_PARSER, 0);
  if (err) {
    goto fail;
  }

  err = bpf_prog_attach(bpf_program__fd(skb_verdict_prog), sock_map_fd, BPF_SK_SKB_STREAM_VERDICT, 0);
  if (err) {
    goto fail;
  }

  fprintf(stdout, "Successfully loaded BPF program.\n");
  return 0;

fail:
  return -1;
}

When I run a workload using wrk2, I receive Non-2XX responses. Sometimes it succeeds but most of the times, it fails.

Here is the output of wrk2:

$ ../wrk2/wrk -D exp -t 1 -c 1 -d 1 -L <URL> -R 1
Running 1s test @ http://10.109.160.25:8080/wrk2-api/post/compose
  1 threads and 1 connections


-----------------------------------------------------------------------
Test Results @ http://10.109.160.25:8080/wrk2-api/post/compose 
  Thread Stats   Avg      Stdev     99%   +/- Stdev
    Latency    23.53ms    0.00us  23.53ms    0.00%
    Req/Sec       -nan      -nan   0.00      0.00%
  Latency Distribution (HdrHistogram - Recorded Latency)
 50.000%   23.53ms
 75.000%   23.53ms
 90.000%   23.53ms
 99.000%   23.53ms
 99.900%   23.53ms
 99.990%   23.53ms
 99.999%   23.53ms
100.000%   23.53ms

  Detailed Percentile spectrum:
       Value   Percentile   TotalCount 1/(1-Percentile)

      23.535     0.000000            1         1.00
      23.535     1.000000            1          inf
#[Mean    =       23.528, StdDeviation   =        0.000]
#[Max     =       23.520, Total count    =            1]
#[Buckets =           27, SubBuckets     =         2048]
-----------------------------------------------------------------------
  2 requests in 1.12s, 430.00B read  ///////// Worked this time
Requests/sec:      1.79  
Transfer/sec:     385.55B

$ strace -ebpf ../wrk2/wrk -D exp -t 1 -c 1 -d 1 -L <URL> -R 1
Running 1s test @ http://10.109.160.25:8080/wrk2-api/post/compose
  1 threads and 1 connections


-----------------------------------------------------------------------
Test Results @ http://10.109.160.25:8080/wrk2-api/post/compose 
  Thread Stats   Avg      Stdev     99%   +/- Stdev
    Latency     2.37ms    0.00us   2.37ms    0.00%
    Req/Sec       -nan      -nan   0.00      0.00%
  Latency Distribution (HdrHistogram - Recorded Latency)
 50.000%    2.37ms
 75.000%    2.37ms
 90.000%    2.37ms
 99.000%    2.37ms
 99.900%    2.37ms
 99.990%    2.37ms
 99.999%    2.37ms
100.000%    2.37ms

  Detailed Percentile spectrum:
       Value   Percentile   TotalCount 1/(1-Percentile)

       2.373     0.000000            1         1.00
       2.373     1.000000            1          inf
#[Mean    =        2.373, StdDeviation   =        0.000]
#[Max     =        2.372, Total count    =            1]
#[Buckets =           27, SubBuckets     =         2048]
-----------------------------------------------------------------------
  2 requests in 1.11s, 644.00B read
  Non-2xx or 3xx responses: 2        ///////// Here is the problem
Requests/sec:      1.81  
Transfer/sec:     581.33B
+++ exited with 0 +++                ///////// No bug in strace?

By checking on the browser, I found that the error is a 500: Internal Server Error: Image of Error

0

There are 0 best solutions below