こんにちは、将棋とサウナが趣味の @kengon です。株式会社ソラコムで OpsDev エンジニア(=SRE)として働いています。
この記事は 株式会社ソラコム Advent Calendar 2021 の 21 日目の記事です。昨日は将棋仲間の @kazntree による GPS マルチユニット SORACOM Edition を使った見守りシステム でした。 何でも監視したくなるSREとしましては大切な家族を 監視 見守るシステムがお手軽に構築できるということで素晴らしいですね。
さて今までの記事では皆さん IoT に関することを書かれていますが、この記事では IoT ぽいことには触れません！私が最近取り組んでいるソラコムでの SRE 業の一部をご紹介させていただきます！
TL;DR
- BPF を使って SCTP の監視ツールを作ってみてるよ。
- BPF 、ハマることも多いけど楽しいよ。
- ソラコムはエンジニア絶賛募集中だよ！明日12月22日（水）にエンジニア向け会社説明会 もやるよ！
SCTP(Stream Control Transmission Protocol) とは
SCTP は TCP や UDP と同じくトランスポート層のプロトコルです。TCP と同様に輻輳制御やデータの到着順序を保証することができます。一般的な知名度はあまりありませんが、携帯電話網のコアネットワークでは SIGTRAN や Diameter などのプロトコルの一部として使用されていまして、ソラコム内でも SCTP を用いたコンポーネントを運用しています。
SCTP の運用
SCTP ではクライアントがサーバに接続する際、 4 way ハンドシェイクを行いアソシエーションを確立します。TCP において 3 way ハンドシェイクによってコネクションを確立する、ようなものですね。Linux の場合、アソシエーションが確立されると /proc/net/sctp/assocs がこのようになります。SCTP の監視としましては、ここの情報を Datadog にアップロードして対向のクライアントとの間にアソシエーションが確立・維持されているかどうかを監視していました。
$ cat /proc/net/sctp/assocs
ASSOC SOCK STY SST ST HBKT ASSOC-ID TX_QUEUE RX_QUEUE UID INODE LPORT RPORT LADDRS <-> RADDRS HBINT INS OUTS MAXRT T1X T2X RTXC wmema wmemq sndbuf rcvbuf
0 0 2 1 3 0 59 0 0 0 112894 80 46081 198.18.0.11 <-> *198.18.0.73 7500 10 10 10 0 0 0 1 0 212992 212992
ところがある時、ソラコム側ではアソシエーションが確立されているように見えているが、対向のクライアントからはアソシエーションが切断されてしまっているように見える、という事象が起こりました。SCTP ではアソシエーションが確立されるとクライアント、サーバがお互いに定期的にHeartbeat、Heartbeat Ack メッセージをやり取りしアソシエーションの状況をモニターするようになっています。この時は /proc/net/sctp/assocs 上は問題ないように見えるのですが、なぜか実際は Heartbeat が止まってしまっている、というような状況でした。
SRE としましてはまずこのような状況に監視で気づけるようにしないといけません。最初は素朴に tcpdump で Heartbeat メッセージをキャプチャして監視することを考えたんですが、BPF の題材としてちょうど良いかなと思い BPF を使って監視ツールを開発してみることにしました。
BPF(Berkeley Packet Filter) とは
Linuxカーネルやアプリケーションの様々なタイミングでユーザの定義したプログラムを実行できるLinuxカーネルの機能です。当初は名前の通りネットワーキングに特化していましたが、現在は オブザーバビリティ(トレーシング)やセキュリティ用途にも利用されています。その拡張性の高さから数年前から注目されている技術です。ちなみに eBPF(extended Berkeley Packet Filter) と呼ばれることもありますが、BPF Perfomance Tools では特に区別せず BPF と呼んでいますのでここでも単に BPF と呼ぶこととします。
今回の件では SCTP Heartbeat メッセージ送受信をしている Linux カーネル内の関数呼び出しをフックすれば監視することができるだろうと思ったのでした。
sctphback
ということで sctphback というプログラムを作ってみました。こちらがソースコードになります。この記事が公開されるまでにプロダクション環境に投入するぞっ！という意気込みでやってたのですが、初めてBPFを利用することもあり色々ハマりましてまだ投入できていませんorz
sctphback のソースコード
#!/usr/bin/env python3
#
# sctphback: Trace SCTP Heartbeat Ack
#
# USAGE: sctphback [-v]
#
# This is an experimental implementation of tracing SCTP Heartbeat Ack message.
# This has been tested only on Ubuntu 20.04.3 LTS, 5.11.0-1022-aws.
#
# Copyright 2021 Kengo Sakai
#
# Licensed under the Apache License, Version 2.0 (the "License")
from bcc import BPF
import argparse
from socket import inet_ntop, ntohs, AF_INET
from struct import pack
import datetime
import time
import datadog
import os
bpf_text = """
#include <bcc/proto.h>
#include <net/sctp/sctp.h>
struct sctp_hb_event_t {
u32 type;
u32 s_addr;
u16 s_port;
u64 ktime;
u64 nonce;
};
BPF_PERF_OUTPUT(sctp_hb_events);
int trace_sctp_sf_sendbeat_8_3_return(struct pt_regs *ctx,
struct net *net,
const struct sctp_endpoint *ep,
const struct sctp_association *asoc,
unsigned long type,
void *arg)
{
struct sctp_transport *transport = (struct sctp_transport *) arg;
union sctp_addr daddr = transport->ipaddr;
if (daddr.sa.sa_family == AF_INET6) {
bpf_trace_printk("AF_INET6 is no supported yet\\n");
return 0;
}
struct sctp_hb_event_t data;
data.type = 0;
data.s_addr = daddr.v4.sin_addr.s_addr;
data.s_port = daddr.v4.sin_port;
data.ktime = bpf_ktime_get_boot_ns();
data.nonce = transport->hb_nonce;
sctp_hb_events.perf_submit(ctx, &data, sizeof(data));
return 0;
}
int trace_sctp_sf_backbeat_8_3_return(struct pt_regs *ctx,
struct net *net,
const struct sctp_endpoint *ep,
const struct sctp_association *asoc,
unsigned long type,
void *arg)
{
struct sctp_sender_hb_info *hbinfo;
struct sctp_chunk *chunk = arg;
union sctp_addr from_addr;
hbinfo = (struct sctp_sender_hb_info *)chunk->skb->data;
from_addr = hbinfo->daddr;
if (from_addr.sa.sa_family == AF_INET6) {
bpf_trace_printk("AF_INET6 is no supported yet\\n");
return 0;
}
struct sctp_hb_event_t data;
data.type = 1;
data.s_addr = from_addr.v4.sin_addr.s_addr;
data.s_port = from_addr.v4.sin_port;
data.ktime = bpf_ktime_get_boot_ns();
data.nonce = hbinfo->hb_nonce;
sctp_hb_events.perf_submit(ctx, &data, sizeof(data));
return 0;
}
"""
TYPE_SENDBEAT = 0
TYPE_BACKBEAT = 1
bpf = BPF(text=bpf_text)
hb_map = {}
def send_metric(address, port, rtt):
metric = "sctp.hb_rtt"
now = time.time()
tags = {
"address": address,
"port": port,
"hostname": os.uname().nodename,
}
datadog.api.Metric.send(metric=metric, points=(now, rtt), type="gauge", tags=tags)
def handle_sctp_hb_event(cpu, data, size):
event = bpf["sctp_hb_events"].event(data)
s_addr = inet_ntop(AF_INET, pack("I", event.s_addr))
s_port = ntohs(event.s_port)
key = "%s:%s" % (s_addr, s_port)
if event.type == TYPE_SENDBEAT:
v = hb_map.get(key, None)
if v:
print("no HB Ack yet from %s" % key)
hb_map[key] = {
"time": datetime.datetime.now(),
"ktime": event.ktime
}
elif event.type == TYPE_BACKBEAT:
v = hb_map.get(key, None)
if v:
rtt = (event.ktime - v.get("ktime"))/1000
print("%s HB Ack received from %s: nonce=%s rtt=%d msec" % (datetime.datetime.now(), key, event.nonce, rtt))
address, port = key.split(':')
send_metric(address, port, rtt)
del hb_map[key]
else:
print("%s HB Ack received from %s: nonce=%s" % (datetime.datetime.now(), key, event.nonce))
return
else:
# must not happen
print("ERROR: Unknown event: %s", event)
def main():
parser = argparse.ArgumentParser(description="Trace SCTP HEARTBEAT ACK")
parser.add_argument('-v', '--verbose', action='store_true', dest='verbose', default=False, help='Verbose mode')
args = parser.parse_args()
datadog.initialize()
bpf.attach_kretprobe(event="sctp_sf_sendbeat_8_3", fn_name="trace_sctp_sf_sendbeat_8_3_return")
bpf.attach_kretprobe(event="sctp_sf_backbeat_8_3", fn_name="trace_sctp_sf_backbeat_8_3_return")
bpf["sctp_hb_events"].open_perf_buffer(handle_sctp_hb_event)
while 1:
try:
if args.verbose:
fields = bpf.trace_fields(nonblocking=True)
if fields[5]:
print(fields)
bpf.perf_buffer_poll()
except KeyboardInterrupt:
exit()
if __name__ == '__main__':
main()
実行するとこのようにHeartbeat Ack受信時にログ出力してくれるのと Datadog に rtt をメトリクスとして送信してくれます。あとは Datadog 側でよしなにアラート設定すればアソシエーションが維持できているか監視できそうですね（まだできていない（涙））
$ sudo -E ./sctphback
2021-12-19 07:46:25.502648 HB Ack received from 198.18.0.73:50157: nonce=8959568737524782058 rtt=265 msec
2021-12-19 07:46:58.269794 HB Ack received from 198.18.0.73:50157: nonce=8959568737524782058 rtt=204 msec
2021-12-19 07:47:31.037866 HB Ack received from 198.18.0.73:50157: nonce=8959568737524782058 rtt=191 msec
少しコードの解説をしますと、ここでカーネル内の SCTP Heartbeat/Heartbeat Ack 送受信に呼ばれる関数をフックし return 時に BPF の自作の関数を呼び出すようにしています。
bpf.attach_kretprobe(event="sctp_sf_sendbeat_8_3", fn_name="trace_sctp_sf_sendbeat_8_3_return")
bpf.attach_kretprobe(event="sctp_sf_backbeat_8_3", fn_name="trace_sctp_sf_backbeat_8_3_return")
BPF の自作関数内では BPF_PERF_OUTPUT で定義したリングバッファ sctp_hb_events を通じて SCTP Heartbeat/Heartbeat Ack の送受信イベントをユーザスペースにプッシュしています。
struct sctp_hb_event_t {
u32 type;
u32 s_addr;
u16 s_port;
u64 ktime;
u64 nonce;
};
BPF_PERF_OUTPUT(sctp_hb_events);
ユーザスペース側ではリングバッファ sctp_hb_events に来た送受信イベントをハンドリングして、RTT 計算したり Datadog にメトリクス送信したり、という感じですね。
bpf["sctp_hb_events"].open_perf_buffer(handle_sctp_hb_event)
苦労したこと
上記のように開発したプログラム自体は複雑なものではないのですが、BPF 初めてということもあり苦労することが多かったです。中でも苦労したのは、開発環境として利用していたカーネル 5.11 では BPF VM からはカーネル内の特定の関数しか呼べない、という制限があることでした。許可されていないカーネル内関数を呼び出すと以下のように BPF がプログラムのロードに失敗します。このメッセージから何が Invalid argument なのか分からずだいぶ時間が溶けたのですが（汗）、Linux カーネルに詳しい同僚の koh++ に相談したところそのような制限があることがわかりました。
bpf: Failed to load program: Invalid argument
last insn is not an exit or jmp
processed 0 insns (limit 1000000) max_states_per_insn 0 total_states 0 peak_states 0 mark_read 0
なお、この制限自体はカーネル 5.13 で改善され、カーネル内の任意の関数を BPF VM から呼ぶ仕組みができたようです。カーネル側にも手を入れる必要がありそうですが、いざという時は便利そうですね。
さいごに
ということで今回は BPF を使って SCTP の監視ツールを作っているお話を紹介させていただきました。BPF には注目していたものの実際に使ったことはなかったので良い機会となりました。ソラコム内では色々使い所が多そうなので今後もぜひ使っていきたい技術ですね。
ちなみにソラコムでは絶賛エンジニア募集中です。ちょうど明日12月22日（水）にエンジニア向け会社説明会がありますのでご興味ある方は参加してみてください！
さて、プロダクション環境に投入しないと。。。