esxtopコマンドで出力した結果をグラフィカルに表示させる「NMONVisualizer」が便利だった！

ESXiの性能情報は、vSphere Clientを使ってグラフを出力することができる。しかし、グラフは複数同時に表示できないため、詳細な分析には向いていない。

そこで、より詳細に分析する場合は、ESXiにsshログインして、esxtopコマンドを使って情報を取得することが多い。

以下に参考までにesxtopの出力例を記載する。

[root@t3011es60:~] esxtop
------------------------------
 2:28:48pm up 82 days 16:16, 556 worlds, 10 VMs, 11 vCPUs; CPU load average: 0.15, 0.10, 0.17
PCPU USED(%):  49  13  20  18 AVG:  25
PCPU UTIL(%):  51  11  21  19 AVG:  26
CORE UTIL(%):  61      40     AVG:  51

      ID      GID NAME             NWLD   %USED    %RUN    %SYS   %WAIT %VMWAI
   19729    19729 t1082w216           7   92.71   93.99    0.02  583.38    0.0
36145555 36145555 esxtop.4631501      1    1.40    1.43    0.01   95.46
11207011 11207011 t1203w28r           6    1.39    1.54    0.01  579.67    0.1
   20007    20007 t3024ce73           6    0.69    0.79    0.02  580.55    0.0
19956461 19956461 t3025ce73           6    0.65    0.71    0.01  580.56    0.0
   18899    18899 t1062w28r           6    0.59    0.74    0.01  580.51    0.2
   18715    18715 t3031vy11           6    0.41    0.47    0.04  580.82    0.1
       2        2 system            113    0.37    0.45    0.00 10948.03
   19714    19714 t3023ce72           6    0.27    0.32    0.01  581.01    0.0
19223894 19223894 t1083xbnt           6    0.18    0.21    0.00  581.11    0.0

～(以下略)～
------------------------------

esxtopコマンドは、当然CLIでしか出力をすることはできないため、瞬間値を見る分には問題ないが、グラフィカルにデータの推移を見る用途には使えない。

一定期間の推移を確認したい場合は、esxtopのバッチモードを利用する。このモードでは、一定間隔ごとに性能情報をテキストファイルに出力することが可能になる。さらに、「NMONVisualizer」と呼ばれるツールを使えば、esxtopが出力したファイルをグラフとして表示することができる。

今回、esxtopのバッチモードとNMONVisualizerを組み合わせて、ESXiの性能情報を取得しグラフ化してみた。大変便利だったので、その手順について記載する。

esxtopのバッチモードで性能情報を取得

以下の書式でesxtopを実行する。

esxtop -b -a -d 間隔(秒) -n 回数 > 出力先ファイル名

※オプションの意味
　・-b : バッチモードで実行
　・-a : すべての情報を出力
　・-d : 取得間隔を秒で指定
　・-n : 取得回数を指定

たとえば、20秒間隔で180回、合計1時間分の性能情報を取得し、/tmp配下に「esxperf_日付_時間.csv」というファイル名で出力させたい場合は、以下の通り実行する。

esxtop -b -a -d 20 -n 180 > /tmp/esxperf_`date +"%Y%m%d_%H%M%S"`.csv

実行後、ファイルサイズを確認してみると、180回のデータで約30MBのサイズになっており、かなりファイルサイズが大きい。

[root@t3011es60:~] du -h /tmp/esxperf_20180419_203356.csv
------------------------------
29.9M   /tmp/esxperf_20180419_203356.csv
------------------------------

出力されたファイルはテキストファイルであり圧縮効果が高いので、tarなどで圧縮してからダウンロードした方がよいだろう。

[root@t3011es60:~] cd /tmp/
[root@t3011es60:/tmp] tar zcf esxperf_20180419_203356.csv.tar.gz esxperf_20180419_203356.csv

圧縮前後のファイルサイズを見ておく。30MBだったファイルは1.2MBまでサイズが縮小される。

[root@t3011es60:/tmp] du -h /tmp/esxperf_20180419_203356.csv*
------------------------------
29.9M   /tmp/esxperf_20180419_203356.csv         ←★圧縮前のサイズ
1.2M    /tmp/esxperf_20180419_203356.csv.tar.gz  ←★圧縮後のサイズ
------------------------------

Tera Termであれば、「SSH SCOP...」の機能を利用して、出力したファイルを入手することができる。

今回の場合であれば、Fromに「/tmp/esxperf_20180419_203356.csv.tar.gz」、Toに任意のフォルダを指定し「Receive」ボタンを押せば、ファイルがダウンロードできる。

NMONVisualizerを使ってグラフを表示

NMONVisualizerは以下からダウンロード可能である。「NMONVisualizer_2018-04-10.jar」というJavaのファイルをダウンロードする(※注：2018/4/22時点)。

NMONVisualizer
https://nmonvisualizer.github.io/nmonvisualizer/

Java Runtimeをインストールした環境であれば、このjarファイルをダブルクリックすれば、NMONVisualizerが起動する。

「File」→「Load...」を選択し、先ほどダウンロードしたesxtopの出力ファイル(解凍済みのもの)を選択する。ファイルに問題がなければ、左ツリーに ESXiサーバーのホスト名と、各種性能情報が表示されるはずである。

なお、ファイル名は拡張子を「.csv」にする必要があるので注意。

実際にいくつかグラフを表示させてみよう。

ESXiサーバーの物理CPUの使用率は、左ツリーの「ESXiホスト名」→「Physical Cpu」で確認することができる。「% Processor Time」、「% Util Time」、「% Core Util Time」の3つのグラフがあるが、物理CPU使用率を見る場合は「% Core Util Time」を見ればよいようだ。
※詳細は本記事の最後に記載した「Processor Utilization Calculations」のURLを参照

仮想マシンごとのグラフも見ることができる。左ツリーの「ESXiホスト名」→「Vcpu」→「仮想マシン名」を選択すればよい。たとえば、CPUのスケジュール待ち時間を表す「CPU Ready」の値は「% Ready」で確認することができる。

同様に仮想マシンごとのディスクの状況も確認することができる。左ツリーの「ESXiホスト名」→「Virtual Disk」→「仮想マシン名」を選択すればよい。IOPSは「Read/sec」や「Write/sec」で確認することができる。

まとめ

vSphere Clientのグラフでは、複数の情報を同時に表示させることができず、性能分析の際に苦労することが多かった。しかし、esxtopとNMONVisualizerを組み合わせれば、詳細な性能情報の調査が可能となり、仮想環境にて性能問題が発生した際の調査手法として、非常に有用であると感じた。

参考

esxtop ユーティリティの使用
https://docs.vmware.com/jp/VMware-vSphere/6.0/com.vmware.vsphere.monitoring.doc/GUID-D89E8267-C74A-496F-B58E-19672CAB5A53.html

バッチ モードのコマンドライン オプション
https://docs.vmware.com/jp/VMware-vSphere/6.0/com.vmware.vsphere.monitoring.doc/GUID-F5EB8133-97FE-4A39-9717-A5FC2B3501AF.html

Processor Utilization Calculations
http://vpivot.com/2010/04/09/processor-utilization-calculations/

Postfixのmain.cfの設定変更は自動反映されるので注意！

Postfixの主要な設定を記載するファイルは、/etc/postfix/main.cfとなる。

main.cfに設定変更を加えたのち、Postfixをreloadすることで設定反映を行うという手順は、さまざまなサイトで言及されている手順となる。

しかし、main.cfの設定は自動反映されることがある。したがって、事前にmain.cfに設定変更を行っておき、任意のタイミングで反映するような作業計画は危険であり、main.cfの設定変更は、設定反映と同じタイミングで実施するよう計画すべきである。

しかし、reloadしなくても反映される場合、どのようなタイミングで反映されるかが気になるので調べてみることにした。

Postfixをデバッグモードにする

通常の設定では詳細なログが出力されないので、Postfixをデバッグモードにする。以下の通り、master.cfのsmtp行に「-v」のオプションを付ける。

# cat /etc/postfix/master.cf | grep -v -e "^#"
------------------------------
smtp      inet  n       -       n       -       -       smtpd -v
------------------------------

設定反映のため、Postfixを再起動する。

# systemctl restart postfix

設定反映のタイミングを確認

Postfixで複数の管理ドメインを持つバーチャルメールボックスの構成としている状況で、管理ドメインの設定ファイルからドメインを1つコメントアウトしてみる。

【main.cfの設定】
# cat /etc/postfix/main.cf | grep virtual
------------------------------
virtual_mailbox_domains = /etc/postfix/vdomains
virtual_mailbox_base = /var/spool/virtual
virtual_mailbox_maps = hash:/etc/postfix/vmailbox
virtual_uid_maps = static:10000
virtual_gid_maps = static:10000
virtual_alias_maps = hash:/etc/postfix/virtual
------------------------------

【変更前】

# cat /etc/postfix/vdomains
------------------------------

example.com

example1.com

example2.com
------------------------------

【変更後】

# cat /etc/postfix/vdomains
------------------------------

#example.com

example1.com

example2.com
------------------------------

通常は自分自身のメールボックスに配送されるexample.com宛てのメールが、コメントアウトの設定が反映されることで上位のMTAにリレーされる。この動作の差異を見ることで設定反映の有無を確認することができる。

変更前にexample.com宛てにメールを送ってみると、以下の通り「delivered to maildir」のログが表示され、自身のサーバー内のメールボックスにメールが送信されたことがわかる。

# tail -100 /var/log/maillog | egrep "example.com.*status"
------------------------------

Apr  9 06:25:26 t1110rh72 postfix/virtual[3102]: BF47F18D2AA7: to=<ex-1@example.com>, relay=virtual, delay=0.06, delays=0.05/0.01/0/0, dsn=2.0.0, status=sent (delivered to maildir)

------------------------------

ここで、example.comのドメインをコメントアウトし、再度メールを送信してみる。しかし、このタイミングでは先ほどと同じ動作となることがログからわかる。つまり、設定はまだ反映されていない。

# tail -100 /var/log/maillog | egrep "example.com.*status"
------------------------------

Apr  9 06:26:31 t1110rh72 postfix/virtual[3102]: 6EEC818D2AA9: to=<ex-1@example.com>, relay=virtual, delay=0.02, delays=0.02/0/0/0, dsn=2.0.0, status=sent (delivered to maildir)

------------------------------

しばらく待ってからメールを送信してみると、ログの内容が変化する。どうやらexample.com宛てのメールが上位のMTAにリレーされているようだ。

# tail -100 /var/log/maillog | egrep "example.com.*status"
------------------------------

Apr  9 06:29:05 t1110rh72 postfix/smtp[3185]: 7E88118D2AAB: to=<ex-1@example.com>, relay=192.168.11.112[192.168.11.112]:25, delay=0.05, delays=0.02/0.01/0.01/0.01, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 70D61A67D9)

------------------------------

当然だが、この作業の間にPostfixのサービス再起動などはしておらず、何らかのタイミングで設定が自動反映されたことになる。

なぜ設定が反映されたかを確認してみる

結果的に、maillogを見ることで、設定反映のタイミングを確認することができた。以下ログの黄色網掛け箇所に注目する。

# tail -f /var/log/maillog | grep postfix

------------------------------

Apr  9 06:26:31 t1110rh72 postfix/smtpd[3095]: private/anvil: wanted attribute: (list terminator)

Apr  9 06:26:31 t1110rh72 postfix/smtpd[3095]: input attribute name: (end)

Apr  9 06:26:31 t1110rh72 postfix/smtpd[3095]: disconnect from t1082w216[192.168.11.82]

Apr  9 06:26:31 t1110rh72 postfix/smtpd[3095]: master_notify: status 1

Apr  9 06:26:31 t1110rh72 postfix/smtpd[3095]: connection closed

Apr  9 06:28:11 t1110rh72 postfix/smtpd[3095]: idle timeout -- exiting

------------------------------

メール送信後のconnection closedから100秒後に、idle timeoutが発生している。

Postfixはメール送信時に送信用プロセスを作成するが(これはprocess generationというログから確認できる)、一定時間メール送信がない場合は、プロセスを停止する動作を行う。そして、再度メールが送信される際に新しくプロセスを作成するのだが、その際にmain.cfの再読み込みを行うようだ。

したがって、main.cfの設定変更を行った後、メール送信がない状態が続いてプロセスが停止した場合、設定が反映されてメールが送信されるということになる。

なお、プロセスのアイドル時間は以下設定値で定義されている。デフォルトで100秒となっている。

# postconf | grep -e "^max_idle"

------------------------------

max_idle = 100s

------------------------------

応答が速いと噂のDNS「1.1.1.1」を使ってみた話

DNSでよく使われるものとして、Google Public DNSの「8.8.8.8」がある。最近、「1.1.1.1」という高速なDNSが利用可能となったようだ。

「1.1.1.1」の説明は以下URLにある。

https://1.1.1.1/

Google Public DNSよりも応答が高速であることをアピールしているが、実際にGoogle Public DNSよりも応答がどの程度応答が速いのか簡単に調べてみることにした。

名前解決対象

対象とした名前解決のFQDNは以下にした。本当はもっと多くのFQDNに対して名前解決の速度を測った方がよいのだろうが、今回は2つのFQDNに対して、Linuxサーバーよりdigコマンドを使って名前解決を100回繰り返して、平均と最大値を確認してみることにする。

------------------------------
www.city.shinjuku.lg.jp
tech-mmmm.blogspot.jp
------------------------------

測定結果と傾向

「1.1.1.1」でwww.city.shinjuku.lg.jpを名前解決

for i in {1..100} ; do dig @1.1.1.1 www.city.shinjuku.lg.jp | grep "Query time"; sleep 0.5; done

結果：
　・平均：6.6ms
　・最大：124ms

→ほとんど10ms以内に応答を返している。100ms以上となったのは1回のみとなった。これだけみると、確かに応答が速い印象。

「Google Public DNS」でwww.city.shinjuku.lg.jpを名前解決

for i in {1..100} ; do dig @8.8.8.8 www.city.shinjuku.lg.jp | grep "Query time"; sleep 0.5; done

結果：
　・平均：21.2ms
　・最大：80ms

→10ms以下の応答も多いが、30～60ms程度要することも多い。遅くはないがすごく速くもない。

「1.1.1.1」でtech-mmmm.blogspot.jpを名前解決

for i in {1..10} ; do dig @1.1.1.1 tech-mmmm.blogspot.jp | grep "Query time"; sleep 0.5; done

結果：
　・平均：32.5ms
　・最大：156ms

→10ms以下の応答もあるのだが、100msをこえる応答が多く、平均値ではそこまで応答が速くならない結果となった。

「Google Public DNS」でtech-mmmm.blogspot.jpを名前解決

for i in {1..10} ; do dig @8.8.8.8 tech-mmmm.blogspot.jp | grep "Query time"; sleep 0.5; done

結果：
　・平均：31.8ms
　・最大：64ms

→30～60ms程度の応答となることが多い。ただし、100msをこえるような応答はなく、安定して応答している印象。

まとめ

「1.1.1.1」はドメインによっては応答の速度が異なり、10ms以内で安定して応答を返すものもあれば、100ms以上の応答が多くなるドメインがあり、必ずしも常に速いわけではないようだ。

Google Public DNSは、応答が100msを超えることはまれではあるが、平均して30～60msと、安定した応答を返すが若干遅めの印象となる。

なお、「1.1.1.1」は代替DNSとして「1.0.0.1」が利用可能である。個人的には、優先DNSを「1.1.1.1」、代替DNSを「8.8.8.8」としておけば問題はないと考える。設定するDNSのサービスを分散させることは、万が一、片方のサービスが停止しても、名前解決が継続できるというメリットもある。

tcpdump入門② (パケットキャプチャからTCP通信を読み解く)

前回、tcpdumpの基本的な使い方を説明したが、今回は実際に通信のキャプチャを確認し、どのような通信が行われているかを確認してみることにする。

★前回はこちら↓
tcpdump入門① (tcpdumpでよく使うオプションたち)
https://tech-mmmm.blogspot.jp/2018/04/tcpdump-tcpdump.html

SMTPのパケットをキャプチャしてみる

実際にSMTPのパケットをキャプチャしてみよう。環境としては以下の通りとなる。

・メール送信元：192.168.11.110
・メール送信先：192.168.11.112

メール送信元からメール送信先に、1通のメールを送信する際のパケットをキャプチャ結果を以下に記載する。

# tcpdump -i 3 -nn host 192.168.11.112 and port 25
------------------------------
tcpdump: verbose output suppressed, use -v or -vv for full protocol decode
listening on eno16780032, link-type EN10MB (Ethernet), capture size 65535 bytes
22:38:40.599031 IP 192.168.11.110.53830 > 192.168.11.112.25: Flags [S], seq 2738265213, win 29200, options [mss 1460,sackOK,TS val 1417334469 ecr 0,nop,wscale 7], length 0
22:38:40.599564 IP 192.168.11.112.25 > 192.168.11.110.53830: Flags [S.], seq 1404691787, ack 2738265214, win 28960, options [mss 1460,sackOK,TS val 2698190197 ecr 1417334469,nop,wscale 7], length 0
22:38:40.599583 IP 192.168.11.110.53830 > 192.168.11.112.25: Flags [.], ack 1, win 229, options [nop,nop,TS val 1417334469 ecr 2698190197], length 0

・・・★①

22:38:40.615489 IP 192.168.11.112.25 > 192.168.11.110.53830: Flags [P.], seq 1:42, ack 1, win 227, options [nop,nop,TS val 2698190213 ecr 1417334469], length 41
22:38:40.615511 IP 192.168.11.110.53830 > 192.168.11.112.25: Flags [.], ack 42, win 229, options [nop,nop,TS val 1417334485 ecr 2698190213], length 0
22:38:40.615568 IP 192.168.11.110.53830 > 192.168.11.112.25: Flags [P.], seq 1:29, ack 42, win 229, options [nop,nop,TS val 1417334485 ecr 2698190213], length 28
22:38:40.615584 IP 192.168.11.112.25 > 192.168.11.110.53830: Flags [.], ack 29, win 227, options [nop,nop,TS val 2698190214 ecr 1417334485], length 0
22:38:40.616588 IP 192.168.11.112.25 > 192.168.11.110.53830: Flags [P.], seq 42:171, ack 29, win 227, options [nop,nop,TS val 2698190215 ecr 1417334485], length 129
22:38:40.616663 IP 192.168.11.110.53830 > 192.168.11.112.25: Flags [P.], seq 29:140, ack 171, win 237, options [nop,nop,TS val 1417334486 ecr 2698190215], length 111
22:38:40.632369 IP 192.168.11.112.25 > 192.168.11.110.53830: Flags [P.], seq 171:236, ack 140, win 227, options [nop,nop,TS val 2698190230 ecr 1417334486], length 65
22:38:40.632458 IP 192.168.11.110.53830 > 192.168.11.112.25: Flags [P.], seq 140:753, ack 236, win 237, options [nop,nop,TS val 1417334502 ecr 2698190230], length 613
22:38:40.637043 IP 192.168.11.112.25 > 192.168.11.110.53830: Flags [P.], seq 236:287, ack 753, win 236, options [nop,nop,TS val 2698190235 ecr 1417334502], length 51

・・・★②

22:38:40.637068 IP 192.168.11.112.25 > 192.168.11.110.53830:  Flags [F.], seq 287, ack 753, win 236, options [nop,nop,TS val 2698190235 ecr 1417334502], length 0
22:38:40.637186 IP 192.168.11.110.53830 > 192.168.11.112.25: Flags [F.], seq 753, ack 288, win 237, options [nop,nop,TS val 1417334507 ecr 2698190235], length 0
22:38:40.637247 IP 192.168.11.112.25 > 192.168.11.110.53830: Flags [.], ack 754, win 236, options [nop,nop,TS val 2698190235 ecr 1417334507], length 0

・・・★③

^C
15 packets captured
15 packets received by filter
0 packets dropped by kernel
------------------------------

★①までが、TCPの通信開始時に実施される3-Wayハンドシェイクとなる。

------------------------------
22:38:40.599031 IP 192.168.11.110.53830 > 192.168.11.112.25: Flags [S], seq 2738265213, win 29200, options [mss 1460,sackOK,TS val 1417334469 ecr 0,nop,wscale 7], length 0
22:38:40.599564 IP 192.168.11.112.25 > 192.168.11.110.53830: Flags [S.], seq 1404691787, ack 2738265214, win 28960, options [mss 1460,sackOK,TS val 2698190197 ecr 1417334469,nop,wscale 7], length 0
22:38:40.599583 IP 192.168.11.110.53830 > 192.168.11.112.25: Flags [.], ack 1, win 229, options [nop,nop,TS val 1417334469 ecr 2698190197], length 0
------------------------------

上記のオレンジ網掛け箇所がTCPパケットのフラグとなっている。フラグについては、tcpdumpのmanページの「TCP Packets」の項目に説明がある。

------------------------------
Flags are some combination of S (SYN), F (FIN), P (PUSH),  R  (RST),  U (URG),  W  (ECN  CWR), E (ECN-Echo) or `.' (ACK), or `none' if no flags are set.
------------------------------

以上より、"S":SYN、".":ACKとなることがわかる。つまり、SYN→SYN/ACK→ACKの3-Wayハンドシェイクが実施されていることがわかる。

また、緑網掛け箇所はデータ長を表すが、3-Wayハンドシェイクではデータを持たないため、0となっている。詳細は割愛するが、length 0の場合、前回受信したシーケンス番号+1の値でackを返す。

★②からは、実際のデータパケットのやり取りとなる。

------------------------------
22:38:40.615489 IP 192.168.11.112.25 > 192.168.11.110.53830: Flags [P.], seq 1:42, ack 1, win 227, options [nop,nop,TS val 2698190213 ecr 1417334469], length 41
22:38:40.615511 IP 192.168.11.110.53830 > 192.168.11.112.25: Flags [.], ack 42, win 229, options [nop,nop,TS val 1417334485 ecr 2698190213], length 0
22:38:40.615568 IP 192.168.11.110.53830 > 192.168.11.112.25: Flags [P.], seq 1:29, ack 42, win 229, options [nop,nop,TS val 1417334485 ecr 2698190213], length 28
22:38:40.615584 IP 192.168.11.112.25 > 192.168.11.110.53830: Flags [.], ack 29, win 227, options [nop,nop,TS val 2698190214 ecr 1417334485], length 0
22:38:40.616588 IP 192.168.11.112.25 > 192.168.11.110.53830: Flags [P.], seq 42:171, ack 29, win 227, options [nop,nop,TS val 2698190215 ecr 1417334485], length 129
22:38:40.616663 IP 192.168.11.110.53830 > 192.168.11.112.25: Flags [P.], seq 29:140, ack 171, win 237, options [nop,nop,TS val 1417334486 ecr 2698190215], length 111
22:38:40.632369 IP 192.168.11.112.25 > 192.168.11.110.53830: Flags [P.], seq 171:236, ack 140, win 227, options [nop,nop,TS val 2698190230 ecr 1417334486], length 65
22:38:40.632458 IP 192.168.11.110.53830 > 192.168.11.112.25: Flags [P.], seq 140:753, ack 236, win 237, options [nop,nop,TS val 1417334502 ecr 2698190230], length 613
22:38:40.637043 IP 192.168.11.112.25 > 192.168.11.110.53830: Flags [P.], seq 236:287, ack 753, win 236, options [nop,nop,TS val 2698190235 ecr 1417334502], length 51
------------------------------

PフラグはPSHフラグとなり、TCPで受信した情報をバッファにためずに、上位アプリケーションに引き渡すように要求するフラグとなる。

tcpdumpではシーケンス番号は相対表示になり1から開始して表示される。1つめのパケットでは、seq1:42までのシーケンス番号でデータ送信を行っており、2つめのパケットではシーケンス番号42までを受け取ったことを示すack 42を返している。

3-Wayハンドシェイクのようなlength 0の場合は、受け取ったシーケンス番号+1をackで返していたが、実際にデータを含むlength 0ではないパケットの場合は、ackは受信済みのシーケンス番号となる点に注意。

このようにTCPの通信では、送信側が送ったシーケンス番号に対して、受信側でどのシーケンス番号まで受信したかを返すことで、データの抜けのない正確な通信が実現できるように設計されている。

★③で通信の終了となるFINパケットのやり取りを実施している。

------------------------------
22:38:40.637068 IP 192.168.11.112.25 > 192.168.11.110.53830:  Flags [F.], seq 287, ack 753, win 236, options [nop,nop,TS val 2698190235 ecr 1417334502], length 0
22:38:40.637186 IP 192.168.11.110.53830 > 192.168.11.112.25: Flags [F.], seq 753, ack 288, win 237, options [nop,nop,TS val 1417334507 ecr 2698190235], length 0
22:38:40.637247 IP 192.168.11.112.25 > 192.168.11.110.53830: Flags [.], ack 754, win 236, options [nop,nop,TS val 2698190235 ecr 1417334507], length 0
------------------------------

お互いにFINフラグを立てたパケットを送信して、TCPの通信をクローズしている。3-Wayハンドシェイクと同様にlength 0のパケットとなり、ack番号は前回受信したシーケンス番号+1の値となっている。

このように、tcpdumpで通信をキャプチャすることで、3-Wayハンドシェイクから始まり、FINパケットてクローズするTCPの通信の流れを確認することができた。

パケットの中身をASCIIで表示させると、もっとわかりやすい！

-Aオプションを使って、パケットの中身を表示させると、もっとわかりやすい。以下キャプチャ例となる。オレンジ網掛けが送信したSMTPコマンドとなり、黄色網掛けが応答となる。

------------------------------
17:40:21.059074 IP 192.168.11.112.25 > 192.168.11.110.54942: Flags [P.], seq 1:42, ack 1, win 227, options [nop,nop,TS val 3717090657 ecr 2436234912], length 41
E..]..@.@..q...p...n....n....N.,...........
..Ma.5..220 t1112rh72.localdomain ESMTP Postfix

↑★SMTP接続に成功して220を返している

17:40:21.059133 IP 192.168.11.110.54942 > 192.168.11.112.25: Flags [.], ack 42, win 229, options [nop,nop,TS val 2436234929 ecr 3717090657], length 0
E..4..@.@......n...p.....N.,n........U.....
.5....Ma
17:40:21.059428 IP 192.168.11.110.54942 > 192.168.11.112.25: Flags [P.], seq 1:29, ack 42, win 229, options [nop,nop,TS val 2436234929 ecr 3717090657], length 28
E..P..@.@......n...p.....N.,n........q.....
.5....MaEHLO t1110rh72.localdomain

↑★EHLOを送信

17:40:21.059526 IP 192.168.11.112.25 > 192.168.11.110.54942: Flags [.], ack 29, win 227, options [nop,nop,TS val 3717090657 ecr 2436234929], length 0
E..4..@.@......p...n....n....N.H...........
..Ma.5..
17:40:21.060047 IP 192.168.11.112.25 > 192.168.11.110.54942: Flags [P.], seq 42:171, ack 29, win 227, options [nop,nop,TS val 3717090658 ecr 2436234929], length 129
E.....@.@......p...n....n....N.H...........
..Mb.5..250-t1112rh72.localdomain
250-PIPELINING
250-SIZE 1048576
250-VRFY
250-ETRN
250-ENHANCEDSTATUSCODES
250-8BITMIME
250 DSN

↑★EHLOの応答

17:40:21.060227 IP 192.168.11.110.54942 > 192.168.11.112.25: Flags [P.], seq 29:146, ack 171, win 237, options [nop,nop,TS val 2436234930 ecr 3717090658], length 117
E.....@.@......n...p.....N.Hn..U...........
.5....MbMAIL FROM:<ex-1@example.com> SIZE=632 BODY=8BITMIME
RCPT TO:<ex-1@example.com> ORCPT=rfc822;ex-1@example.com
DATA

↑★MAIL FROM、RCPT TO、DATAを送信

17:40:21.078089 IP 192.168.11.112.25 > 192.168.11.110.54942: Flags [P.], seq 171:236, ack 146, win 227, options [nop,nop,TS val 3717090676 ecr 2436234930], length 65
E..u..@.@..V...p...n....n..U.N.............
..Mt.5..250 2.1.0 Ok
250 2.1.5 Ok
354 End data with <CR><LF>.<CR><LF>

↑★MAIL FROM、RCPT TO、DATAの応答
------------------------------

以上のように、SMTPのコマンドのやり取りを確認することができる。

Wiresharkでみると、さらにわかりやすい！

文字で見るよりも、GUIでグラフィカルに見た方が当然わかりやすい。ということで、前回説明した-wオプションにてパケットキャプチャをファイル出力し、Wiresharkで確認すると、もっと見やすくなる。

tcpdump入門① (tcpdumpでよく使うオプションたち)

サーバー間通信がうまく動作しない場合などに、パケットキャプチャをして調査することがある。Linuxの場合、パケットキャプチャツールとして、tcpdumpが定番となっている。名前がTCPとなっているが、UDPの通信も確認できる。

本記事では2回にわけて、tcpdumpの使い方を説明する。1回目となる今回はtcpdumpの基礎的な使用方法と、よく使うオプションの説明を行う。次回では、実際にtcpdumpで取得したTCP通信のパケットキャプチャのデータを見て、どのような通信が行われているかを読み解いてみることにする。

tcpdumpの使い方

まずは、調査対象のインターフェース番号を確認する必要がある。-Dオプションで確認ができる。通常、CentOS 7では、3番が通常のネットワークインターフェースとなるようだ。

# tcpdump -D
------------------------------
1.nflog (Linux netfilter log (NFLOG) interface)
2.nfqueue (Linux netfilter queue (NFQUEUE) interface)
3.eno16780032
4.any (Pseudo-device that captures on all interfaces)
5.lo
------------------------------

インタフェースを指定し、すべてのパケットをキャプチャするコマンドは以下の通りとなる。なお、tcpdumpを終了する場合は、Ctrl+Cにて行うこと。

# tcpdump -i 3
------------------------------
tcpdump: verbose output suppressed, use -v or -vv for full protocol decode
listening on eno16780032, link-type EN10MB (Ethernet), capture size 65535 bytes
10:30:56.887081 IP 192.168.11.110.ssh > 192.168.11.82.62780: Flags [P.], seq 2961489592:2961489832, ack 1367601915, win 274, length 240
10:30:56.887192 IP 192.168.11.82.62780 > 192.168.11.110.ssh: Flags [.], ack 240, win 8210, length 0
10:30:56.887514 IP 192.168.11.110.53846 > 192.168.11.31.domain: 17612+ PTR? 82.11.168.192.in-addr.arpa. (44)
10:30:56.887647 IP 192.168.11.31 > 192.168.11.110: ICMP 192.168.11.31 udp port domain unreachable, length 80
10:30:56.887674 IP 192.168.11.110.34744 > 192.168.11.31.domain: 17612+ PTR? 82.11.168.192.in-addr.arpa. (44)

～(以下略)～
------------------------------

上記のようにキャプチャはできるものの、すべてのパケットがキャプチャされてしまうことから大量の情報が表示されてしまい、解析することが困難となる。このような場合は、次節で述べるフィルター機能を使うとよい。

tcpdumpでよく使うフィルター機能

tcpdumpでは、条件に合致したパケットのみ表示させるフィルター機能が存在する。よく使うフィルター機能について、以下に記載する。

特定のホストの通信をキャプチャする

# tcpdump -i 3 host 192.168.11.112

特定のプロトコルの通信をキャプチャする

# tcpdump -i 3 port 25

特定のホストの特定のプロトコルの通信をキャプチャする

複数条件指定にて対応する。andやorを使えばよい。

# tcpdump -i 3 host 192.168.11.112 and port 25

送信元ホストと送信先ホストを指定する

送信元はsrc、送信先はdstで指定することができる。ただし、srcとdstを指定した場合は、戻りパケットがキャプチャされないため、通信の全体を確認したい場合は不向きである。

# tcpdump -i 3 src 192.168.11.112 and dst 192.168.11.110

tcpdumpでよく使うオプション

フィルター以外によく使うオプションを以下に記載する。

キャプチャの表示を詳細化する

以下3種類があり、下に行くほど詳細になるようだが、具体的にどのように詳細になるかというと不明である。とりあえず詳細にしたければ、一番詳細な-vvvにしておくとよいと思われる。

tcpdump -i 3 -v host 192.168.11.112
tcpdump -i 3 -vv host 192.168.11.112
tcpdump -i 3 -vvv host 192.168.11.112

IPアドレスをホスト名に変換させないで表示させる

tcpdumpは、デフォルトでIPアドレスをhostsやDNSで名前解決して表示する。IPアドレスの方がわかりやす場合もあるので、名前解決を抑止する場合は-nオプションを付与する。

tcpdump -i 3 -n host 192.168.11.112

プロトコル名をポート番号で表示させる

tcpdumpは、デフォルトでポート番号をプロトコル名に変換して表示する(たとえば、22番ポートならsshと表示される)。しかしこの機能は、かえってキャプチャを見る際にわかりにくくなることもあるので、そのような場合は、-nnオプションを使ってポート番号で表示させることができる。

tcpdump -i 3 -nn host 192.168.11.112

通信内容をASCIIで表示させる

-Aオプションを使うことで、実際の通信内容がASCIIで表示させる。これにより、通信内容を視覚的に理解しやすくなる。

tcpdump -i 3 -A host 192.168.11.112

以下表示例。

------------------------------
17:40:21.060227 IP 192.168.11.110.54942 > 192.168.11.112.25: Flags [P.], seq 29:146, ack 171, win 237, options [nop,nop,TS val 2436234930 ecr 3717090658], length 117
E.....@.@......n...p.....N.Hn..U...........
.5....MbMAIL FROM:<ex-1@example.com> SIZE=632 BODY=8BITMIME
RCPT TO:<ex-1@example.com> ORCPT=rfc822;ex-1@example.com
DATA
------------------------------

パケットキャプチャをファイルで出力する

-wオプションの後にファイル名を指定することで、パケットキャプチャをファイルとして出力することができる。

なお、-s 0のオプションは、古いtcpdumpでは1つのパケットの取得上限サイズが96バイトとなっており、それ以上の情報は切り捨てられてしまうので、65535バイトまで受け取ることができるようにする設定となる。ただし、最近のtcpdump(少なくともCentOS 7のtcpdump)ではデフォルト65535となったようなので、-sオプションは省略しても問題ない。

tcpdump -i 3 -s 0 -w test.cap host 192.168.11.112

出力されたファイルを確認すると、tcpdumpユーザーでファイルが作成されていることがわかる。

# ls -l

------------------------------
-rw-r--r--  1 tcpdump tcpdump  4277  3月 31 07:22 test.cap
------------------------------

このファイルはWiresharkで開くことができる。Wiresharkによって通信の流れがグラフィカルかつ整理されて表示することができるようになり、通信解析が非常にはかどる。

以上がtcpdumpの基本的な使用方法となる。次回は、tcpdumpで実際の通信の流れを調べてみることにする。

★次回はこちら↓
tcpdump入門② (パケットキャプチャからTCP通信を読み解く)
https://tech-mmmm.blogspot.jp/2018/04/tcpdump-tcp.html