SystemTapを利用する方法もありますがシステムがクラッシュすることもあるので、ここではより簡単、安全、パワフルにカーネルをトレースしてみたいと思います。2年ほど前にここでBCCを紹介しましたが、今回はbcc-toolsというツールを使ってみます。
今年2月にアイルランドで講演する機会を頂きましたが、bccを知らない方も多いようでしたので、簡単に紹介するとbccとkernelの関係性は次のようになります。
bcc-toolsというパッケージをインストールするとすぐに実行できる便利なツールがあります。ちなみにRHEL9.1では120以上同梱しています。
では早速インストールして、UDPパケットを送信するプロセスを全てトレースしてみましょう。ここではRHEL8.2の環境で試しています。
# dnf install bcc-tools
# pwd
/usr/share/bcc/tools/
# ./trace 'udp_sendmsg' -T
この状態で、別のターミナルを開いて、npingで強制的に UDPパケットを送ってみます。
# nping --echo-client "public" echo.nmap.org --udp
Starting Nping 0.7.70 ( https://nmap.org/nping ) at 2023-08-17 11:58 JST
SENT (1.8487s) UDP 192.168.122.44:53 > 45.33.32.156:40125 ttl=64 id=1189 iplen=28
CAPT (1.9920s) UDP XX.YY.164.193:36533 > 45.33.32.156:40125 ttl=52 id=1189 iplen=28
RCVD (2.2570s) ICMP [45.33.32.156 > 192.168.122.44 Port unreachable (type=3/code=3) ] IP [ttl=52 id=30541 iplen=56 ]
SENT (2.8488s) UDP 192.168.122.44:53 > 45.33.32.156:40125 ttl=64 id=1189 iplen=28
CAPT (2.9199s) UDP XX.YY.164.193:36533 > 45.33.32.156:40125 ttl=52 id=1189 iplen=28
RCVD (3.0890s) ICMP [45.33.32.156 > 192.168.122.44 Port unreachable (type=3/code=3) ] IP [ttl=52 id=30833 iplen=56 ]
SENT (3.8495s) UDP 192.168.122.44:53 > 45.33.32.156:40125 ttl=64 id=1189 iplen=28
CAPT (3.9201s) UDP XX.YY.164.193:36533 > 45.33.32.156:40125 ttl=52 id=1189 iplen=28
RCVD (4.1290s) ICMP [45.33.32.156 > 192.168.122.44 Port unreachable (type=3/code=3) ] IP [ttl=52 id=30983 iplen=56 ]
SENT (4.8505s) UDP 192.168.122.44:53 > 45.33.32.156:40125 ttl=64 id=1189 iplen=28
CAPT (4.9302s) UDP XX.YY.164.193:36533 > 45.33.32.156:40125 ttl=52 id=1189 iplen=28
RCVD (5.1690s) ICMP [45.33.32.156 > 192.168.122.44 Port unreachable (type=3/code=3) ] IP [ttl=52 id=31262 iplen=56 ]
SENT (5.8514s) UDP 192.168.122.44:53 > 45.33.32.156:40125 ttl=64 id=1189 iplen=28
CAPT (5.9167s) UDP XX.YY.164.193:36533 > 45.33.32.156:40125 ttl=52 id=1189 iplen=28
^C
Max rtt: 408.256ms | Min rtt: 240.119ms | Avg rtt: 311.557ms
Raw packets sent: 5 (140B) | Rcvd: 4 (224B) | Lost: 1 (20.00%)| Echoed: 5 (140B)
Nping done: 1 IP address pinged in 6.00 seconds
するとトレースしたターミナルでは、このような結果を表示することができます。
# ./trace 'udp_sendmsg' -T
TIME PID TID COMM FUNC
11:58:46 19726 20021 rhsmcertd-worke udp_sendmsg
11:58:46 19726 20021 rhsmcertd-worke udp_sendmsg
11:58:47 19726 20022 rhsmcertd-worke udp_sendmsg
11:58:47 19726 20022 rhsmcertd-worke udp_sendmsg
11:58:47 19726 20023 rhsmcertd-worke udp_sendmsg
11:58:47 19726 20023 rhsmcertd-worke udp_sendmsg
11:58:47 19726 20024 rhsmcertd-worke udp_sendmsg
11:58:47 19726 20024 rhsmcertd-worke udp_sendmsg
11:58:52 20041 20041 nping udp_sendmsg
11:58:52 20041 20041 nping udp_sendmsg
しっかりとUDPパケットを送信しているプロセスをトレースできることが確認できました。
今回は、udp_sendmsgというカーネル関数をトレースしていますが、ここを変更するだけでさまざまな関数をトレースすることができます。ちなみに、udp_sendmsgは、net/ipv4/udp.cで次のように定義されています。
int udp_sendmsg(struct sock *sk, struct msghdr *msg, size_t len)
{
struct inet_sock *inet = inet_sk(sk);
struct udp_sock *up = udp_sk(sk);
DECLARE_SOCKADDR(struct sockaddr_in *, usin, msg->msg_name);
struct flowi4 fl4_stack;
struct flowi4 *fl4;
int ulen = len;
struct ipcm_cookie ipc;
struct rtable *rt = NULL;
int free = 0;
int connected = 0;
__be32 daddr, faddr, saddr;
__be16 dport;
u8 tos;
int err, is_udplite = IS_UDPLITE(sk);
int corkreq = up->corkflag || msg->msg_flags&MSG_MORE;
int (*getfrag)(void *, char *, int, int, int, struct sk_buff *);
struct sk_buff *skb;
struct ip_options_data opt_copy;
if (len > 0xFFFF)
return -EMSGSIZE;
...
いかがでしょうか。非常に簡単にカーネルの関数をトレースできるので、何か別の機会にも応用できそうです。
コメント