straceで通信データを観察

先日、自社製品であるProDHCPの調査を行う際に、straceを使ってみて便利でしたので、簡単に紹介しましょう（というより、自分の備忘録？）。

straceはシステムコールをトレースするもので、実行中のプロセスにも簡単にアタッチしてトレースができます。実際にProDHCPのプロセスにstraceでアタッチして様子を見てみましょう。

# strace -p 17030 -s 1600 -yy -o /tmp/strace.log

-pでプロセスIDを指定し、-sで出力文字数をイーサフレームのサイズより少し大きく指定。-yyオプションでファイルディスクリプタ番号をファイル名、ソケットを送信元と送信先のIPアドレスとポート番号に置き換えを指定します。最後に-oでトレース結果をファイルに出力とします。

トレースファイルの中を見て、select()の後にread()しているところを探してみると、以下の感じに。

select(1024, [6<socket:[31143910]> 7<socket:[31143911]> 8<socket:[31143914]> 9<socket:[31143915]> 11<socket:[31143917
]> 12<socket:[31143918]> 14<socket:[31143920]> 15<socket:[31143921]> 16<socket:[31143923]> 17<socket:[31143925]> 20<s
ocket:[31143986]>], NULL, NULL, {0, 30000}) = 2 (in [11 12], left {0, 12134})
read(11<socket:[31143917]>, "\0\f)\275\3071\0\24\362H\353H\10\0E\0\1H\304\210\0\0\377\21t\342\300\250\0\376\300\
250\376\352\0C\0C\0014\271g\1\1\6\1\255\273\331V\0\0\200\0\0\0\0\0\0\0\0\0\0\0\0\0\300\250\0\376\0\2\313\3\2
64\270\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\
0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0
\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0
\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0c\202Sc5\1\1=\7\1\0\2\313\3\264\270
\377\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0", 2048) = 342

ここで、read()で読み取ったデータをバイナリに変換し、DHCPとして解釈してみると・・・

00:14:f2:48:eb:48->00:0c:29:bd:c7:31
192.168.0.254:67->192.168.254.234:67
op=1:BOOTREQUEST
htype=1:HTYPE_ETHER
hlen=6
hops=1
xid=1457109933
secs=0
flags=80
ciaddr=0.0.0.0
yiaddr=0.0.0.0
siaddr=0.0.0.0
giaddr=192.168.0.254
chaddr=00:02:cb:03:b4:b8
sname=
file=
options
53:DHCP message type:1:1:DHCPDISCOVER
61:client-identifier:7:01:00:02:CB:03:B4:B8
255:end

ちゃんとDHCPリクエストのパケットそのものの中身が得られます。こちらはリンクレイヤーで読み取っているのでイーサフレームからの情報が得られています。

さらに、sendto()しているところを探すと、

sendto(12, "\2\1\6\1\255\273\331V\0\0\200\0\0\0\0\0\300\250\0\252\0\0\0\0\300\250\0\376\0\2\313\3\264\
270\0\0\0\0\0\0\0\0\0\0ns\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0
\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\
0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0
\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0c\202Sc
5\1\0026\4\300\250\376\3523\4\0\0\0161:\4\0\0\1,;\4\0\0\2\r\377\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0
\0\0\0\0\0\0\0\0\0\0\0\0", 300, 0, {sa_family=AF_INET, sin_port=htons(67), sin_addr=inet_addr("192.168.0.254")}, 16) 
= 300

こんな感じになっており、こちらもデータ部分をバイナリにしてDHCPとして解析すると、

op=2:BOOTREPLY
htype=1:HTYPE_ETHER
hlen=6
hops=1
xid=1457109933
secs=0
flags=80
ciaddr=0.0.0.0
yiaddr=192.168.0.170
siaddr=0.0.0.0
giaddr=192.168.0.254
chaddr=00:02:cb:03:b4:b8
sname=ns
file=
options
53:DHCP message type:1:2:DHCPOFFER
54:server identifier:4:192.168.254.234
51:IP address lease time:4:3633
58:renewal (T1) time value:4:300
59:rebinding (T1) time value:4:525
255:end

きちんとレスポンスデータの中身が分かりました。ここでの送信はsendto()なので、UDPの中身だけです。

これまで、ネットワークプログラムの送受信データの調査では、デバッガを使ったり、コアダンプをさせたり、別にパケットキャプチャを取ったりして行うことが多かったのですが、実運用中のシステムではなかなか実施するタイミングが難しいことが多く、悩みの一つでした。straceは別の目的でたまに使っていましたが、今回、よーく情報を見ていると、送受信しているデータそのものが入っていることに今さらながら気がつき、実運用中のシステムでも比較的簡単に状況を把握できて便利だと感動したのでした。

なお、8進表記のデータをバイナリ化したり、DHCPパケットとして解析させるのが少し手間ですが、そんなツールも探せばありそうな気がするものの、私にとっては探すよりプログラミングする方が簡単なので、簡単な変換プログラムを作って行いました。-xを指定すれば16進表記で出してくれるようなのでその方が簡単だったかもしれません。