Tag: ebpf

Leverage comprehensive debugging tricks in one shot

Last Friday, a colleague told me that when connecting an invalid address, the client using gRPC will block forever. To verify it, I use the example code shipped in gRPC:

GreeterClient greeter(grpc::CreateChannel(
  "localhost:50051", grpc::InsecureChannelCredentials()));

Change the "localhost:50051" to "badhost:50051", then compile and execute the program. Sure enough, the client hang without any response. At the outset, I thought it should be a common issue, and there must be a solution already. So I just submitted a post in the discussion group, although there was some responses, but since they were not the satisfactory explanations, I knew I need to trouble-shooting myself.

(1) The first thing I wanted to make sure was whether the network card had sent requests to badhost or not, so I used tcpdump to capture the packets:

$ sudo tcpdump -A -s 0 'port 50051' -i enp7s0f0

But there isn’t any data captured. To double-confirm, I also used tcpconnect program to check:

$ sudo tcpconnect -P 50051
PID    COMM         IP SADDR            DADDR            DPORT

Still nothing output.

(2) Although I couldn’t find the connect request to port 50051, no matter what application on *NIX, it will definitely call connect function at the end. So I changed the tactic, and tried to find who calls the connect:

a) Build gRPC with debugging info (The reason of using “PKG_CONFIG_PATH=/usr/lib/openssl-1.0/pkgconfig” is here):

$ PKG_CONFIG_PATH=/usr/lib/openssl-1.0/pkgconfig CC=clang CXX=clang++ CFLAGS="-g -O0" CXXFLAGS="-g -O0" make

b) Modify the Makefile to build client program with debugging info:

CXXFLAGS += -g -std=c++11

c) Use gdb to debug the program, after starting it, set breakpoint at connect function:

$ gdb -q greeter_client
Reading symbols from greeter_client...done.
(gdb) start
Temporary breakpoint 1 at 0x146fe: file greeter_client.cc, line 74.
Starting program: /home/xiaonan/Project/grpc/examples/cpp/helloworld/greeter_client
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/usr/lib/libthread_db.so.1".

Temporary breakpoint 1, main (argc=1, argv=0x7fffffffea88) at greeter_client.cc:74
74      int main(int argc, char** argv) {
(gdb) b connect
Breakpoint 2 at 0x7ffff6619b80 (2 locations)

Then continue executing the program. When the breakpoint was hit, check the stack:

(gdb) c
Continuing.
[New Thread 0x7ffff4edc700 (LWP 28396)]
[New Thread 0x7ffff46db700 (LWP 28397)]
[Switching to Thread 0x7ffff4edc700 (LWP 28396)]

Thread 2 "greeter_client" hit Breakpoint 2, 0x00007ffff6619b80 in connect () from /usr/lib/libc.so.6

(gdb) bt
#0  0x00007ffff6619b80 in connect () from /usr/lib/libc.so.6
#1  0x00007ffff664e61e in open_socket () from /usr/lib/libc.so.6
#2  0x00007ffff664f156 in __nscd_open_socket () from /usr/lib/libc.so.6
#3  0x00007ffff664ccc6 in __nscd_getai () from /usr/lib/libc.so.6
#4  0x00007ffff66038bc in gaih_inet.constprop () from /usr/lib/libc.so.6
#5  0x00007ffff6604724 in getaddrinfo () from /usr/lib/libc.so.6
#6  0x00007ffff714ee1e in ?? () from /usr/lib/libgrpc.so.4
#7  0x00007ffff714f38c in ?? () from /usr/lib/libgrpc.so.4
#8  0x00007ffff714d020 in ?? () from /usr/lib/libgrpc.so.4
#9  0x00007ffff714cf12 in ?? () from /usr/lib/libgrpc.so.4
#10 0x00007ffff71fff57 in ?? () from /usr/lib/libgrpc.so.4
#11 0x00007ffff7755049 in start_thread () from /usr/lib/libpthread.so.0
#12 0x00007ffff6618f0f in clone () from /usr/lib/libc.so.6

Then continue to run the program, the breakpoint was hit again:

(gdb) bt
#0  0x00007ffff6619b80 in connect () from /usr/lib/libc.so.6
#1  0x00007ffff664e61e in open_socket () from /usr/lib/libc.so.6
#2  0x00007ffff664f156 in __nscd_open_socket () from /usr/lib/libc.so.6
#3  0x00007ffff664ccc6 in __nscd_getai () from /usr/lib/libc.so.6
#4  0x00007ffff66038bc in gaih_inet.constprop () from /usr/lib/libc.so.6
#5  0x00007ffff6604724 in getaddrinfo () from /usr/lib/libc.so.6
#6  0x00007ffff714ee1e in ?? () from /usr/lib/libgrpc.so.4
#7  0x00007ffff714f38c in ?? () from /usr/lib/libgrpc.so.4
#8  0x00007ffff714d020 in ?? () from /usr/lib/libgrpc.so.4
#9  0x00007ffff714cf12 in ?? () from /usr/lib/libgrpc.so.4
#10 0x00007ffff71fff57 in ?? () from /usr/lib/libgrpc.so.4
#11 0x00007ffff7755049 in start_thread () from /usr/lib/libpthread.so.0
#12 0x00007ffff6618f0f in clone () from /usr/lib/libc.so.6
(gdb)

Oh, I see! The resolving of badhost must be failed, so there would definitely no subsequent connecting port 50051. But why the client was trying to resolve name again and again? If I find this cause, it can explain why client was blocking.

(3) Since there is ?? from /usr/lib/libgrpc.so.4, I can’t know which function was the culprit. I can go over the code, but I think I need the direct proof. Build gRPC with CC=clang CXX=clang++ CFLAGS="-g -O0" CXXFLAGS="-g -O0" seems not enough. After some tweaking, I come out the following solutions:

a) According to the Makefile:

# TODO(nnoble): the strip target is stripping in-place, instead
# of copying files in a temporary folder.
# This prevents proper debugging after running make install.

“make install” will strip the debugging information, so instead of executing “make install” command, I set LD_LIBRARY_PATH environment variable to let client link library in the specified directory:

$ export LD_LIBRARY_PATH=/home/xiaonan/Project/grpc/libs/opt

b) Hardcode -g in the Makefile:

CFLAGS += -g -std=c99 -Wsign-conversion -Wconversion $(W_SHADOW) $(W_EXTRA_SEMI)
CXXFLAGS += -g -std=c++11

Then the symbols can all be resolved:

(gdb) bt
#0  0x00007ffff6486b80 in connect () from /usr/lib/libc.so.6
#1  0x00007ffff64bb61e in open_socket () from /usr/lib/libc.so.6
#2  0x00007ffff64bbae2 in __nscd_get_mapping () from /usr/lib/libc.so.6
#3  0x00007ffff64bbed5 in __nscd_get_map_ref () from /usr/lib/libc.so.6
#4  0x00007ffff64b9ba3 in __nscd_getai () from /usr/lib/libc.so.6
#5  0x00007ffff64708bc in gaih_inet.constprop () from /usr/lib/libc.so.6
#6  0x00007ffff6471724 in getaddrinfo () from /usr/lib/libc.so.6
#7  0x00007ffff7473ec5 in blocking_resolve_address_impl (name=0x55555578edf0 "badhost:50051",
    default_port=0x555555790220 "https", addresses=0x55555578f1f0) at src/core/lib/iomgr/resolve_address_posix.c:83
#8  0x00007ffff74742e3 in do_request_thread (exec_ctx=0x7ffff5043c30, rp=0x55555578e630, error=<optimized out>)
    at src/core/lib/iomgr/resolve_address_posix.c:157
#9  0x00007ffff7472b86 in run_closures (exec_ctx=<optimized out>, list=...) at src/core/lib/iomgr/executor.c:64
#10 executor_thread (arg=0x555555789fc0) at src/core/lib/iomgr/executor.c:152
#11 0x00007ffff74e5286 in thread_body (v=<optimized out>) at src/core/lib/support/thd_posix.c:42
#12 0x00007ffff6181049 in start_thread () from /usr/lib/../lib64/libpthread.so.0
#13 0x00007ffff6485f0f in clone () from /usr/lib/libc.so.6

Now I just need to step-into code, and the information of this issue can also be referred here.

During the whole process, I used sniffer tool (tcpdump), kernel tracing tool(tcpconnect, which belongs to bcc and utilizes eBPF), networking knowledge (set breakpoint on connect function), debugging tool (gdb), and the trick of linking library (set LD_LIBRARY_PATH to bypass installing gRPC), that’s why I call the whole procedure “leverage comprehensive debugging tricks”.

 

Use pdb to help understand python program

As I have mentioned in Why do I need a debugger?:

(3) Debugger is a good tool to help you understand code.

So when I come across difficulty to understand vfscount.py code in bcc project, I know it is time to resort to pdb, python‘s debugger, to help me.

The thing which confuses me is here:

counts = b.get_table("counts")
for k, v in sorted(counts.items(), key=lambda counts: counts[1].value):
    print("%-16x %-26s %8d" % (k.ip, b.ksym(k.ip), v.value))

From previous code:

BPF_HASH(counts, struct key_t, u64, 256);

It seems the v‘s type is u64, and I can’t figure out why use v.value to fetch its data here.

pdb‘s manual is very succinct and its command is so similar with gdb‘s, so it is no learning curve for me. Just launch a debugging session and set breakpoint at “counts = b.get_table("counts")” line:

# python -m pdb vfscount.py
> /root/Project/bcc/tools/vfscount.py(14)<module>()
-> from __future__ import print_function
(Pdb) b vfscount.py:49

Start the program and press Ctrl-C after seconds; the breakpoint will be hit:

(Pdb) r
Tracing... Ctrl-C to end.
^C
ADDR             FUNC                          COUNT
> /root/Project/bcc/tools/vfscount.py(49)<module>()
-> counts = b.get_table("counts")

Step into get_table method, and single-step every line. Before leaving method, check the type of keytype and leaftype:

-> counts = b.get_table("counts")
(Pdb) s
--Call--
> /usr/lib/python3.6/site-packages/bcc/__init__.py(416)get_table()
-> def get_table(self, name, keytype=None, leaftype=None, reducer=None):
(Pdb) n
> /usr/lib/python3.6/site-packages/bcc/__init__.py(417)get_table()
-> map_id = lib.bpf_table_id(self.module, name.encode("ascii"))
......
(Pdb) p leaf_desc
b'"unsigned long long"'
(Pdb) n
> /usr/lib/python3.6/site-packages/bcc/__init__.py(430)get_table()
-> leaftype = BPF._decode_table_type(json.loads(leaf_desc.decode()))
(Pdb)
> /usr/lib/python3.6/site-packages/bcc/__init__.py(431)get_table()
-> return Table(self, map_id, map_fd, keytype, leaftype, reducer=reducer)
(Pdb) p leaftype
<class 'ctypes.c_ulong'>
(Pdb) p keytype
<class 'bcc.key_t'>

Yeah! The magic is here: leaftype‘s type is not pure u64, but ctypes.c_ulong. According to document:

>>> print(i.value)
42

We should use v.value to get its internal data.

Happy pdbing! Happy python debugging!

Parse BPF_ARRAY macro in bcc

BPF_ARRAY is a very common macro used in bcc scripts. To analyze it, I put all BPF_ARRAY related macros in an example file:

// Changes to the macro require changes in BFrontendAction classes
#define BPF_F_TABLE(_table_type, _key_type, _leaf_type, _name, _max_entries, _flags) \
struct _name##_table_t { \
  _key_type key; \
  _leaf_type leaf; \
  _leaf_type * (*lookup) (_key_type *); \
  _leaf_type * (*lookup_or_init) (_key_type *, _leaf_type *); \
  int (*update) (_key_type *, _leaf_type *); \
  int (*insert) (_key_type *, _leaf_type *); \
  int (*delete) (_key_type *); \
  void (*call) (void *, int index); \
  void (*increment) (_key_type); \
  int (*get_stackid) (void *, u64); \
  _leaf_type data[_max_entries]; \
  int flags; \
}; \
__attribute__((section("maps/" _table_type))) \
struct _name##_table_t _name = { .flags = (_flags) }

#define BPF_TABLE(_table_type, _key_type, _leaf_type, _name, _max_entries) \
BPF_F_TABLE(_table_type, _key_type, _leaf_type, _name, _max_entries, 0);

#define BPF_ARRAY1(_name) \
  BPF_TABLE("array", int, u64, _name, 10240)
#define BPF_ARRAY2(_name, _leaf_type) \
  BPF_TABLE("array", int, _leaf_type, _name, 10240)
#define BPF_ARRAY3(_name, _leaf_type, _size) \
  BPF_TABLE("array", int, _leaf_type, _name, _size)

// helper for default-variable macro function
#define BPF_ARRAYX(_1, _2, _3, NAME, ...) NAME

// Define an array function, some arguments optional
// BPF_ARRAY(name, leaf_type=u64, size=10240)
#define BPF_ARRAY(...) \
  BPF_ARRAYX(__VA_ARGS__, BPF_ARRAY3, BPF_ARRAY2, BPF_ARRAY1)(__VA_ARGS__)

enum stat_types {
  S_COUNT = 1,
  S_MAXSTAT
};

void main(void)
{
  BPF_ARRAY(stats, u64, S_MAXSTAT + 1); 
}

Use gcc -E to preprocess it (I have formatted code to make it clear):

# 1 "test.c"
# 1 "<built-in>"
# 1 "<command-line>"
# 31 "<command-line>"
# 1 "/usr/include/stdc-predef.h" 1 3 4
# 32 "<command-line>" 2
# 1 "test.c"
# 38 "test.c"
enum stat_types {
    S_COUNT = 1,
    S_MAXSTAT
};

void main(void)
{
    struct stats_table_t { 
      int key; 
      u64 leaf; 
      u64 * (*lookup) (int *); 
      u64 * (*lookup_or_init) (int *, u64 *); 
      int (*update) (int *, u64 *); 
      int (*insert) (int *, u64 *); 
      int (*delete) (int *);
      void (*call) (void *, int index); 
      void (*increment) (int); 
      int (*get_stackid) (void *, u64); 
      u64 data[S_MAXSTAT + 1]; 
      int flags; 
    }; 
    __attribute__((section("maps/" "array"))) struct stats_table_t stats = { .flags = (0) };;
}

Let’s analyze how the final result is got:

(1)

BPF_ARRAY(stats, u64, S_MAXSTAT + 1)

will be expanded to (__VA_ARGS__ will be replaced by all arguments):

BPF_ARRAYX(stats, u64, S_MAXSTAT + 1, BPF_ARRAY3, BPF_ARRAY2, BPF_ARRAY1)(stats, u64, S_MAXSTAT + 1)

(2) According to:

// helper for default-variable macro function
#define BPF_ARRAYX(_1, _2, _3, NAME, ...) NAME

BPF_ARRAYX(stats, u64, S_MAXSTAT + 1, BPF_ARRAY3, BPF_ARRAY2, BPF_ARRAY1)(stats, u64, S_MAXSTAT + 1) will be replaced by following code:

BPF_ARRAY3(stats, u64, S_MAXSTAT + 1)

We can compared it to BPF_ARRAY1 (both _leaf_type and size have default values) and BPF_ARRAY2 (only size have default value.).

(3) Convert BPF_ARRAY3 to final BPF_F_TABLE is more straightforward, so I won’t drill that down.

Use the same method you can analyze other macros, such as BPF_HASH. Hope this small post can give you a tip!

The anatomy of “Hello World” python program in bcc

The bcc gives a simple Hello World program analysis, but I want to give a more detailed anatomy of it:

from bcc import BPF

BPF(text='int kprobe__sys_clone(void *ctx) { bpf_trace_printk("Hello, World!\\n"); return 0; }').trace_print()

(1)

from bcc import BPF

bcc is a package, and it will be installed in Python‘s site-packages directory. Take my server as an example:

>>> import bcc
>>> bcc.__path__
['/usr/lib/python3.6/site-packages/bcc']

BPF is a class defined in __init__.py file of bcc:

......
class BPF(object):
# From bpf_prog_type in uapi/linux/bpf.h
    SOCKET_FILTER = 1
    KPROBE = 2
......

(2) Divide

BPF(text='int kprobe__sys_clone(void *ctx) { bpf_trace_printk("Hello, World!\\n"); return 0; }').trace_print()

into 2 parts:

BPF(text='int kprobe__sys_clone(void *ctx) { bpf_trace_printk("Hello, World!\\n"); return 0; }')

and

trace_print()

a)

BPF(text='int kprobe__sys_clone(void *ctx) { bpf_trace_printk("Hello, World!\\n"); return 0; }')

This statement will create a BPF object, and the code is simplified as following:

......
from .libbcc import lib, _CB_TYPE, bcc_symbol, _SYM_CB_TYPE 
......
class BPF(object):
......
    def __init__(self, src_file="", hdr_file="", text=None, cb=None, debug=0,
        cflags=[], usdt_contexts=[]):
        ......

        if text:
            self.module = lib.bpf_module_create_c_from_string(text.encode("ascii"),
            self.debug, cflags_array, len(cflags_array))
        else:
            ......

        self._trace_autoload()

Check libbcc.py:

lib = ct.CDLL("libbcc.so.0", use_errno=True)

We can see lib module is indeed libbcc dynamic library, and bpf_module_create_c_from_string is implemented as this:

void * bpf_module_create_c_from_string(const char *text, unsigned flags, const char *cflags[], int ncflags) {
    auto mod = new ebpf::BPFModule(flags);
    if (mod->load_string(text, cflags, ncflags) != 0) {
        delete mod;
        return nullptr;
    }
    return mod;
}

We won’t delve it too much, and just know it returns a ebpf module is enough.

For self._trace_autoload() part, we can check _trace_autoload method definition:

def _trace_autoload(self):
    for i in range(0, lib.bpf_num_functions(self.module)):
        func_name = str(lib.bpf_function_name(self.module, i).decode())
        if func_name.startswith("kprobe__"):
            fn = self.load_func(func_name, BPF.KPROBE)
            self.attach_kprobe(event=fn.name[8:], fn_name=fn.name)
        elif func_name.startswith("kretprobe__"):
            fn = self.load_func(func_name, BPF.KPROBE)
            self.attach_kretprobe(event=fn.name[11:], fn_name=fn.name)
        elif func_name.startswith("tracepoint__"):
            fn = self.load_func(func_name, BPF.TRACEPOINT)
            tp = fn.name[len("tracepoint__"):].replace("__", ":")
            self.attach_tracepoint(tp=tp, fn_name=fn.name)

Based on above code, we can see bcc now supports kprobe, kretprobe and tracepoint. For Hello World example, it actually execute attach_kprobemethod:

def attach_kprobe(self, event="", fn_name="", event_re="",
        pid=-1, cpu=0, group_fd=-1):

    ......

    event = str(event)
    self._check_probe_quota(1)
    fn = self.load_func(fn_name, BPF.KPROBE)
    ev_name = "p_" + event.replace("+", "_").replace(".", "_")
    res = lib.bpf_attach_kprobe(fn.fd, 0, ev_name.encode("ascii"),
            event.encode("ascii"), pid, cpu, group_fd,
            self._reader_cb_impl, ct.cast(id(self), ct.py_object))
    res = ct.cast(res, ct.c_void_p)
    ......
    self._add_kprobe(ev_name, res)
    return self

Finally, it will call libbcc‘s bpf_attach_kprobe function. Until now, the kprobe is attached successfully, and attach_kprobe will return a BPF object.

(b)

BPF(...).trace_print()

The trace_print method is not too hard:

def trace_print(self, fmt=None):
    ......
    try:
        while True:
            if fmt:
                fields = self.trace_fields(nonblocking=False)
                if not fields: continue
                line = fmt.format(*fields)
            else:
                line = self.trace_readline(nonblocking=False)
            print(line)
            sys.stdout.flush()
    except KeyboardInterrupt:
        exit()

For fmt=None case, it just calls trace_readline(), which read from trace pipe, and prints it on the stdout:

print(line)
sys.stdout.flush()

That’s all, and hope you enjoy bcc and ebpf!

Install bcc on ArchLinux

To install bcc on ArchLinux, firstly you need to setup yaourt from AUR:

$ git clone https://aur.archlinux.org/yaourt.git
$ cd yaourt
$ makepkg -si

Then execute yaourt bcc command:

# yaourt bcc
1 aur/bcc 0.3.0-1 [installed] (17) (2.51)
    BPF Compiler Collection - C library and examples
2 aur/bcc-git v0.1.8.r330.52cd371-1 (2) (0.06)
    BPF Compiler Collection - C library and examples
3 aur/bcc-tools 0.3.0-1 [installed] (17) (2.51)
    BPF Compiler Collection - Tools
4 aur/bcc-tools-git v0.1.8.r330.52cd371-1 (2) (0.06)
    BPF Compiler Collection - Tools
......

Select the order number of bcc, bcc-tools, python-bcc and python2-bcc, and install them.

Once finished, the bcc would be installed in the directory of /usr/share/bcc:

# ls
examples  man  tools

To facilitate your daily work, you can add man pages and tools in your .bashrc file:

MANPATH=/usr/share/bcc/man:$MANPATH
PATH=/usr/share/bcc/tools:$PATH

You can also install from source code:

git clone https://github.com/iovisor/bcc.git
mkdir bcc/build; cd bcc/build
cmake .. -DCMAKE_INSTALL_PREFIX=/usr
make
sudo make install

P.S. To run tools shipped in bcc, you need to install kernel header files:

sudo pacman -S linux-headers

Update on 28/10/2020：
Currently, bcc is the official package and split to 3 pieces: bcc, bcc-tools and python-bcc. Please install all 3 packages. If you forgot to install python-bcc, when running commands from bcc-tools, you will come across following errors:

# /usr/share/bcc/tools/execsnoop
Traceback (most recent call last):
  File "/usr/share/bcc/tools/execsnoop", line 21, in <module>
    from bcc import BPF
ModuleNotFoundError: No module named 'bcc'