Fix bpf log buffer for large bpf program: (#680)

Use tempfile module to create a temp file

Fix some review input

Fix style check

Style

Style check

Remove builtin module from python test to run fedora ctest

Let the program calling bpf_prog_load to handle the log buffer

Check max instruction before the syscall. Fix other review comment

src/cc/libbpf.c

@@ -25,6 +25,7 @@
 #include <linux/rtnetlink.h>
 #include <linux/unistd.h>
 #include <linux/version.h>
+#include <linux/bpf_common.h>
 #include <net/ethernet.h>
 #include <net/if.h>
 #include <stdio.h>
@@ -33,6 +34,7 @@
 #include <sys/ioctl.h>
 #include <sys/resource.h>
 #include <unistd.h>
+#include <stdbool.h>
 
 #include "libbpf.h"
 #include "perf_reader.h"
@@ -134,14 +136,16 @@ int bpf_get_next_key(int fd, void *key, void *next_key)
 
 #define ROUND_UP(x, n) (((x) + (n) - 1u) & ~((n) - 1u))
 
-char bpf_log_buf[LOG_BUF_SIZE];
-
 int bpf_prog_load(enum bpf_prog_type prog_type,
                   const struct bpf_insn *insns, int prog_len,
                   const char *license, unsigned kern_version,
                   char *log_buf, unsigned log_buf_size)
 {
   union bpf_attr attr;
+  char *bpf_log_buffer = NULL;
+  unsigned buffer_size = 0;
+  int ret = 0;
+
   memset(&attr, 0, sizeof(attr));
   attr.prog_type = prog_type;
   attr.insns = ptr_to_u64((void *) insns);
@@ -155,7 +159,17 @@ int bpf_prog_load(enum bpf_prog_type prog_type,
   if (log_buf)
     log_buf[0] = 0;
 
-  int ret = syscall(__NR_bpf, BPF_PROG_LOAD, &attr, sizeof(attr));
+  if (attr.insn_cnt > BPF_MAXINSNS) {
+    ret = -1;
+    errno = EINVAL;
+    fprintf(stderr,
+            "bpf: %s. Program too large (%d insns), at most %d insns\n\n",
+            strerror(errno), attr.insn_cnt, BPF_MAXINSNS);
+    return ret;
+  }
+
+  ret = syscall(__NR_bpf, BPF_PROG_LOAD, &attr, sizeof(attr));
+   
   if (ret < 0 && errno == EPERM) {
     // When EPERM is returned, two reasons are possible:
     //  1. user has no permissions for bpf()
@@ -175,11 +189,36 @@ int bpf_prog_load(enum bpf_prog_type prog_type,
   }
 
   if (ret < 0 && !log_buf) {
+
+    buffer_size = LOG_BUF_SIZE;
     // caller did not specify log_buf but failure should be printed,
-    // so call recursively and print the result to stderr
-    bpf_prog_load(prog_type, insns, prog_len, license, kern_version,
-        bpf_log_buf, LOG_BUF_SIZE);
-    fprintf(stderr, "bpf: %s\n%s\n", strerror(errno), bpf_log_buf);
+    // so repeat the syscall and print the result to stderr
+    for (;;) {
+         bpf_log_buffer = malloc(buffer_size);
+         if (!bpf_log_buffer) {
+             fprintf(stderr,
+                     "bpf: buffer log memory allocation failed for error %s\n\n",
+                     strerror(errno));
+             return ret;
+         }
+
+         attr.log_buf = ptr_to_u64(bpf_log_buffer);
+         attr.log_size = buffer_size;
+         attr.log_level = bpf_log_buffer ? 1 : 0;
+
+         ret = syscall(__NR_bpf, BPF_PROG_LOAD, &attr, sizeof(attr));
+         if (ret < 0 && errno == ENOSPC) {
+             free(bpf_log_buffer);
+             bpf_log_buffer = NULL;
+             buffer_size <<= 1;
+         } else {
+             break;
+         }
+    }
+
+    fprintf(stderr, "bpf: %s\n%s\n", strerror(errno), bpf_log_buffer);
+
+    free(bpf_log_buffer); 
   }
   return ret;
 }

src/libbpf.h

@@ -65,7 +65,6 @@ void * bpf_open_perf_buffer(perf_reader_raw_cb raw_cb, void *cb_cookie, int pid,
 int bpf_attach_xdp(const char *dev_name, int progfd);
 
 #define LOG_BUF_SIZE 65536
-extern char bpf_log_buf[LOG_BUF_SIZE];
 
 // Put non-static/inline functions in their own section with this prefix +
 // fn_name to enable discovery by the bcc library.

src/python/bcc/__init__.py

@@ -44,6 +44,7 @@ TRACEFS = "/sys/kernel/debug/tracing"
 DEBUG_LLVM_IR = 0x1
 DEBUG_BPF = 0x2
 DEBUG_PREPROCESSOR = 0x4
+LOG_BUFFER_SIZE = 65536
 
 class SymbolCache(object):
     def __init__(self, pid):
@@ -218,29 +219,32 @@ class BPF(object):
     def load_func(self, func_name, prog_type):
         if func_name in self.funcs:
             return self.funcs[func_name]
-
         if not lib.bpf_function_start(self.module, func_name.encode("ascii")):
             raise Exception("Unknown program %s" % func_name)
-
-        log_buf = ct.create_string_buffer(65536) if self.debug else None
-
-        fd = lib.bpf_prog_load(prog_type,
-                lib.bpf_function_start(self.module, func_name.encode("ascii")),
-                lib.bpf_function_size(self.module, func_name.encode("ascii")),
-                lib.bpf_module_license(self.module),
-                lib.bpf_module_kern_version(self.module),
-                log_buf, ct.sizeof(log_buf) if log_buf else 0)
+        buffer_len = LOG_BUFFER_SIZE
+        while True:
+            log_buf = ct.create_string_buffer(buffer_len) if self.debug else None
+            fd = lib.bpf_prog_load(prog_type,
+                    lib.bpf_function_start(self.module, func_name.encode("ascii")),
+                    lib.bpf_function_size(self.module, func_name.encode("ascii")),
+                    lib.bpf_module_license(self.module),
+                    lib.bpf_module_kern_version(self.module),
+                    log_buf, ct.sizeof(log_buf) if log_buf else 0)
+            if fd < 0 and ct.get_errno() == errno.ENOSPC and self.debug:
+                buffer_len <<= 1
+            else:
+                break
 
         if self.debug & DEBUG_BPF and log_buf.value:
             print(log_buf.value.decode(), file=sys.stderr)
 
         if fd < 0:
+            errstr = os.strerror(ct.get_errno())
             if self.debug & DEBUG_BPF:
-                errstr = os.strerror(ct.get_errno())
                 raise Exception("Failed to load BPF program %s: %s" %
                                 (func_name, errstr))
             else:
-                raise Exception("Failed to load BPF program %s" % func_name)
+                raise Exception("Failed to load BPF program %s: %s" % (func_name, errstr))
 
         fn = BPF.Function(self, func_name, fd)
         self.funcs[func_name] = fn

tests/python/CMakeLists.txt

@@ -16,6 +16,8 @@ endif()
 
 add_test(NAME py_test_stat1_b WORKING_DIRECTORY ${CMAKE_CURRENT_SOURCE_DIR}
   COMMAND ${TEST_WRAPPER} py_stat1_b namespace ${CMAKE_CURRENT_SOURCE_DIR}/test_stat1.py test_stat1.b proto.b)
+add_test(NAME py_test_bpf_log WORKING_DIRECTORY ${CMAKE_CURRENT_SOURCE_DIR}
+  COMMAND ${TEST_WRAPPER} py_bpf_prog namespace ${CMAKE_CURRENT_SOURCE_DIR}/test_bpf_log.py)
 add_test(NAME py_test_stat1_c WORKING_DIRECTORY ${CMAKE_CURRENT_SOURCE_DIR}
   COMMAND ${TEST_WRAPPER} py_stat1_c namespace ${CMAKE_CURRENT_SOURCE_DIR}/test_stat1.py test_stat1.c)
 #add_test(NAME py_test_xlate1_b WORKING_DIRECTORY ${CMAKE_CURRENT_SOURCE_DIR}

tests/python/test_bpf_log.py

+#!/usr/bin/env python
+# Copyright (c) PLUMgrid, Inc.
+# Licensed under the Apache License, Version 2.0 (the "License")
+
+from bcc import BPF
+from simulation import Simulation
+import sys
+import os
+import tempfile
+from unittest import main, TestCase
+
+
+error_msg = "R0 invalid mem access 'map_value_or_null'\n"
+
+text = """
+       #include <uapi/linux/ptrace.h>
+       #include <bcc/proto.h>
+       BPF_TABLE("hash", int, int, t1, 10);
+       int sim_port(struct __sk_buff *skb) {
+           int x = 0, *y;
+       """
+repeat = """
+           y = t1.lookup(&x);
+           if (!y) return 0;
+           x = *y;
+         """
+end = """
+           y = t1.lookup(&x);
+           x = *y;
+           return 0; 
+        }
+      """
+for i in range(0,300):
+    text += repeat
+text += end
+
+class TestBPFProgLoad(TestCase):
+
+    def setUp(self):
+        self.fp = tempfile.TemporaryFile()
+        os.dup2(self.fp.fileno(), sys.stderr.fileno())
+
+    def tearDown(self):
+        self.fp.close()
+        
+
+    def test_log_debug(self):
+        b = BPF(text=text, debug=2)
+        try:
+            ingress = b.load_func("sim_port",BPF.SCHED_CLS)
+        except Exception:
+            self.fp.flush()
+            self.fp.seek(0)
+            self.assertEqual(error_msg in self.fp.read(), True)
+
+
+    def test_log_no_debug(self):
+        b = BPF(text=text, debug=0)
+        try:
+            ingress = b.load_func("sim_port",BPF.SCHED_CLS)
+        except Exception:
+            self.fp.flush()
+            self.fp.seek(0)
+            self.assertEqual(error_msg in self.fp.read(), True)
+
+
+if __name__ == "__main__":
+    main()
+
+