ebpf[1]是一种创新的革命性技术,它能在内核中运行沙箱程序, 而无需修改内核源码或者加载内核模块。将 Linux 内核变成可编程之后,就能基于现有的(而非增加新的)抽象层来打造更加智能、 功能更加丰富的基础设施软件,而不会增加系统的复杂度,也不会牺牲执行效率和安全性。
BPF的第一个版本在1994年问世。我们在使用tcpdump工具编写规则的时候其实就使用到它了,该工具用于查看或”嗅探”网络数据包。
使用ebpf技术,你可以从安全、跟踪&性能分析、网络、观测&监控等方向提供新的思路和技术:
你可以自己编写bpf程序,进行定制化的逻辑处理和分析,也可以使用大神们写好的工具,利用这些工具对程序进行通用的性能分析和跟踪。本文主要介绍使用一些工具对rpcx微服务程序进行通用的分析,既然是通用的,你可以可以对其它的Go程序进行分析,而且不仅限于Go程序,其它应用程序甚至内核你可以进行分析和跟踪。
自己编写bpf程序我准备再新开一篇文章介绍。
这一次主要介绍bcc提供的相关工具[2]和bpftrace[3]。
bcc是用于创建基于eBPF的高效内核跟踪和操作程序的工具包,其中包括一些有用的命令行工具和示例。BCC简化了用C进行内核检测的eBPF程序的编写,包括LLVM的包装器以及Python和Lua的前端。它还提供了用于直接集成到应用程序中的高级库。
bpftrace是Linux eBPF的高级跟踪语言。它的语言受awk和C以及DTrace和SystemTap等以前的跟踪程序的启发。bpftrace使用LLVM作为后端将脚本编译为eBPF字节码,并利用BCC作为与Linux eBPF子系统以及现有Linux跟踪功能和连接点进行交互的库。
既然要使用ebpf分析程序,首先我们要有一个程序。这里我选取了rpcx[4]一个最简单的例子,实现一个乘法的最小的微服务。
这个程序的代码可以在rpcx-examples-102basic[5]下载到。
服务端的程序如下:
package main
import (
"context"
"flag"
"fmt"
example "github.com/rpcxio/rpcx-examples"
"github.com/smallnest/rpcx/server"
)
var (
addr = flag.String("addr", "localhost:8972", "server address")
)
type Arith struct{}
// 使用ebpf跟踪这个服务调用
func (t *Arith) Mul(ctx context.Context, args example.Args, reply *example.Reply) error {
reply.C = args.A * args.B
fmt.Println("C=", reply.C)
return nil
}
func main() {
flag.Parse()
s := server.NewServer()
s.RegisterName("Arith", new(Arith), "")
err := s.Serve("tcp", *addr)
if err != nil {
panic(err)
}
}
使用go build server.go
编译出server
程序并运行(./server
)。
客户端程序如下:
package main
import (
"context"
"flag"
"log"
"time"
"github.com/smallnest/rpcx/protocol"
example "github.com/rpcxio/rpcx-examples"
"github.com/smallnest/rpcx/client"
)
var (
addr = flag.String("addr", "localhost:8972", "server address")
)
func main() {
flag.Parse()
d, _ := client.NewPeer2PeerDiscovery("tcp@"+*addr, "")
opt := client.DefaultOption
opt.SerializeType = protocol.JSON
xclient := client.NewXClient("Arith", client.Failtry, client.RandomSelect, d, opt)
defer xclient.Close()
args := example.Args{
A: 10,
B: 20,
}
for {
reply := &example.Reply{}
err := xclient.Call(context.Background(), "Mul", args, reply)
if err != nil {
log.Fatalf("failed to call: %v", err)
}
log.Printf("%d * %d = %d", args.A, args.B, reply.C)
time.Sleep(time.Second)
}
}
客户端每一秒会调用Arith.Mul
微服务一次,微服务的逻辑也很简单,就是执行乘法,并把结果返回给客户端。
作为演示,本文只跟踪服务端Arith.Mul
调用情况。
bcc提供了很多的基于bpf的分析程序,如下图(大神Brendan Gregg整理的经典图)
这里我们会选取几个相关的工具演示如何使用这些工具分析运行中的程序。注意是运行中的程序,我们并没有给程序添加额外的一些埋点。
首先你得安装bcc套件,而且你的Linux内核还要足够新,在一些大厂的机房内,还有一些内核版本的2.6.x服务器,这些老的内核服务器不能支持ebpf或者ebpf的新特性。
我是在我的阿里云的一台虚机上测试的,它的版本是:
直接yum install bcc-tools
就可以安装这些工具。
如果你是其它的版本的操作系统,你可以参考bcc的安装文档进行安装: bcc/INSTALL[6]。
在使用工具分析之前,你首先要知道你的微服务Arith.Mul
在符号表中的名称,你可以使用objdump查询到:
[root@lab server]# objdump -t server|grep Mul|grep main
000000000075a5e0 g F .text 00000000000000d0 main.(*Arith).Mul
它的名称是main.(*Arith).Mul
,下面我们会使用这个名称分析这个微服务。
确保刚才的服务器一直在运行中。
funccount 用来统计一段时间内某个函数的调用次数。
在server所在的目录下执行下面的命令(如果在不同的路径,你需要更改命令参数中程序的路径):
[root@lab server]# funccount -d 10 './server:main.*.Mul'
Tracing 1 functions for "b'./server:main.*.Mul'"... Hit Ctrl-C to end.
FUNC COUNT
b'main.(*Arith).Mul' 10
Detaching...
[root@lab server]#
这里我们设置观察时间是10秒,可以看到在这10秒内,这个函数被调用了10次。
它包含几个参数,比如你可以持续观察,每5秒输出一次结果:
[root@lab server]# funccount -Ti 5 './server:main.*.Mul'
Tracing 1 functions for "b'./server:main.*.Mul'"... Hit Ctrl-C to end.
18:08:29
FUNC COUNT
b'main.(*Arith).Mul' 5
我们甚至可以用它进行Go GC相关函数的跟踪:
[root@lab server]# funccount -d 10 './server:runtime.*.gc*'
Tracing 21 functions for "b'./server:runtime.*.gc*'"... Hit Ctrl-C to end.
FUNC COUNT
b'runtime.(*gcControllerState).update' 2
b'runtime.mallocgc' 250
抑或是跟踪Go运行时的调度:
[root@lab server]# funccount -d 10 './server:runtime.schedule'
Tracing 1 functions for "b'./server:runtime.schedule'"... Hit Ctrl-C to end.
FUNC COUNT
b'runtime.schedule' 20
Detaching...
funclatency统计函数的执行的耗时情况。如果我们想分析Arith.Mul
方法执行的情况,我们可以使用下面的命令,它会用直方图的形式展示这个函数调用的耗时分布:
[root@lab server]# funclatency -d 10 './server:main.*.Mul'
Tracing 1 functions for "./server:main.*.Mul"... Hit Ctrl-C to end.
Function = b'main.(*Arith).Mul' [359284]
nsecs : count distribution
0 -> 1 : 0 | |
2 -> 3 : 0 | |
4 -> 7 : 0 | |
8 -> 15 : 0 | |
16 -> 31 : 0 | |
32 -> 63 : 0 | |
64 -> 127 : 0 | |
128 -> 255 : 0 | |
256 -> 511 : 0 | |
512 -> 1023 : 0 | |
1024 -> 2047 : 0 | |
2048 -> 4095 : 0 | |
4096 -> 8191 : 0 | |
8192 -> 16383 : 0 | |
16384 -> 32767 : 7 |****************************************|
32768 -> 65535 : 3 |***************** |
avg = 31978 nsecs, total: 319783 nsecs, count: 10
我们统计了10秒的数据。可以看到期间这个函数被调用了10次。平均耗时31微秒。
如果我们想检查线上的程序有没有长尾的现象,使用这个工具很容易分析统计。
funcslower 这个工具可以跟踪内核和程序的执行慢的函数,比如使用下面的命令:
[root@lab server]# funcslower -u 10 './server:main.(*Arith).Mul'
Tracing function calls slower than 10 us... Ctrl+C to quit.
COMM PID LAT(us) RVAL FUNC
server 359284 44.75 0 ./server:main.(*Arith).Mul
server 359284 30.97 0 ./server:main.(*Arith).Mul
server 359284 33.38 0 ./server:main.(*Arith).Mul
server 359284 31.28 0 ./server:main.(*Arith).Mul
你甚至可以打印出堆栈信息:
[root@lab server]funcslower -UK -u 10 './server:main.(*Arith).Mul'
Tracing function calls slower than 10 us... Ctrl+C to quit.
COMM PID LAT(us) RVAL FUNC
server 359284 31.20 0 ./server:main.(*Arith).Mul
b'runtime.call64.abi0'
b'runtime.reflectcall'
b'reflect.Value.call'
b'reflect.Value.Call'
b'github.com/smallnest/rpcx/server.(*service).call'
b'github.com/smallnest/rpcx/server.(*Server).handleRequest'
b'github.com/smallnest/rpcx/server.(*Server).serveConn.func2'
b'runtime.goexit.abi0'
server 359284 32.23 0 ./server:main.(*Arith).Mul
b'runtime.call64.abi0'
b'runtime.reflectcall'
b'reflect.Value.call'
b'reflect.Value.Call'
b'github.com/smallnest/rpcx/server.(*service).call'
bcc提供了一堆的对tcp的跟踪情况,我们可以针对不同的场景选择使用相应的工具。
比如我们如果关注连接的建立情况,可以使用tcptracer
:
[root@lab lib]# tcptracer
Tracing TCP established connections. Ctrl-C to end.
T PID COMM IP SADDR DADDR SPORT DPORT
C 360005 client 4 127.0.0.1 127.0.0.1 43126 8972
X 360005 client 6 [::1] [::1] 43010 8972
A 359284 server 4 127.0.0.1 127.0.0.1 8972 43126
X 360005 client 4 127.0.0.1 127.0.0.1 43126 8972
X 359284 server 4 127.0.0.1 127.0.0.1 8972 43126
C 360009 client 4 127.0.0.1 127.0.0.1 43130 8972
X 360009 client 6 [::1] [::1] 43014 8972
A 359284 server 4 127.0.0.1 127.0.0.1 8972 43130
另外还有一堆的xxxxsnoop
程序,可以对特定的系统调用进行跟踪。
有时候,我们想使用脚本实现一些定制化的跟踪,比如类似awk这样的工具,可以提供简单的脚本编写。
bpftrace就是这样的工具, 它使用LLVM作为后端将脚本编译为eBPF字节码,并利用BCC作为与Linux eBPF子系统以及现有Linux跟踪功能和连接点进行交互的库。
bpftrace参考手册可以在bpftrace reference_guide[7]找到。
以我们的Arith.Mul
为例,我们可以使用下面的命令,在函数调用时加入探针,把输入的参数打印出来:
[root@lab server]# bpftrace -e 'uprobe:./server:main.*.Mul {printf("%s - %s: arg1: %d, arg2: %d\n", comm, func, arg0, arg1)}'
Attaching 1 probe...
server - main.(*Arith).Mul: arg1: 10, arg2: 20
server - main.(*Arith).Mul: arg1: 10, arg2: 20
server - main.(*Arith).Mul: arg1: 10, arg2: 20
为什么arg0,arg1就能把参数打印出来呢?简单说,我们的微服务参数正好是两个int64的整数,正好对应arg0,arg1。
rpcx的服务返回值也是当做参数传入的,函数调用的时候还没有设置,所以你如果打印arg3并不是reply返回值。
这个时候我们需要移动探针,加一个偏移量,加多少的偏移量呢?通过反汇编我们看到加92时返回值已经赋值了,所以使用下面的命令就可以打印返回值了(这个时候第一个参数就被覆盖掉了):
[root@lab server]# bpftrace -e 'uprobe:./server:main.*.Mul+92 {printf("%s - %s: reply: %d\n", comm, func, arg0)}'
Attaching 1 probe...
server - main.(*Arith).Mul: reply: 200
server - main.(*Arith).Mul: reply: 200
server - main.(*Arith).Mul: reply: 200
Go自1.17开始已经改成了基于寄存器的调用惯例,所以这里使用了内建的arg0、arg1、..., 如果你使用更早的Go版本,这里你可以换成sarg0,sarg1,...试试(stack arguments)。
ebpf: https://ebpf.io/zh-cn/
[2]bcc提供的相关工具: https://github.com/iovisor/bcc
[3]bpftrace: https://github.com/iovisor/bpftrace
[4]rpcx: https://github.com/smallnest/rpcx
[5]rpcx-examples-102basic: https://github.com/rpcxio/rpcx-examples/tree/master/102basic
[6]bcc/INSTALL: https://github.com/iovisor/bcc/blob/master/INSTALL.md
[7]bpftrace reference_guide: https://github.com/iovisor/bpftrace/blob/master/docs/reference_guide.md#20-override-override-return-value