使用 ebpf 技術跟蹤 rpcx 微服務

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 跟蹤功能和連接點進行交互的庫。

簡單的 rpcx 微服務程序

既然要使用 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 套件

首先你得安裝 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

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

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

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'

tcp 系列工具

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程序,可以對特定的系統調用進行跟蹤。

bpftrace

有時候,我們想使用腳本實現一些定製化的跟蹤,比如類似 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)。

參考資料

[1]

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

本文由 Readfog 進行 AMP 轉碼,版權歸原作者所有。
來源https://mp.weixin.qq.com/s/KIsIA2tPzXZwGJSrfxm54g