接続ライフサイクルによるカーネルデバッグ手順

はじめに

Connection Life Cycleはデバッグツールです。

このツールは、コネクションとパケットによってデバッグメッセージを階層的に表示するフォーマットされたデバッグ出力ファイル（Rubyフォーマット）を生成します。

最初の階層レベルでは、接続が表示されます。
接続を展開すると、この接続のすべてのパケットが表示されます。

重要 - このツールはエキスパートモードで、通常のカーネルデバッグフラグ (カーネルデバッグモジュールとデバッグフラグ)。

セキュリティゲートウェイ/各クラスタメンバの構文

デバッグキャプチャを開始するには

conn_life_cycle.sh -a start -o /<Path>/<Name of Raw Debug Output File> [{-t | -T}] [[-f "<Filter1>"] [-f "<Filter2>"] [-f "<Filter3>] [-f "<Filter4>] [-f "<Filter5>"]]

デバッグキャプチャを停止してフォーマットされたデバッグ出力を準備するには

conn_life_cycle.sh -a stop -o /<Path>/<Name of Formatted Debug Output File>

スケーラブルプラットフォームセキュリティグループ:

デバッグキャプチャを開始するには

g_all conn_life_cycle.sh -a start -o /<Path>/<Name of Raw Debug Output File> [{-t | -T}] [[-f "<Filter1>"] [-f "<Filter2>"] [-f "<Filter3>] [-f "<Filter4>] [-f "<Filter5>"]]

デバッグキャプチャを停止してフォーマットされたデバッグ出力を準備するには

g_all conn_life_cycle.sh -a stop -o /<Path>/<Name of Formatted Debug Output File>

パラメータ

説明

-a start

-a stop

必須です。

アクションを指定します：

start- 有効にしたデバッグフラグと指定したデバッグフィルタに基づいて、デバッグキャプチャを開始する。
stop- デバッグキャプチャを停止し、カーネルデバッグオプションをリセットし、カーネルデバッグフィルタをリセットする。

-t | -T

オプションです。

各デバッグメッセージの前にあるタイムスタンプの解像度を指定します。

-t- タイムスタンプをミリ秒単位で表示します。
-T- タイムスタンプをマイクロ秒単位で表示します。

ベストプラクティス - デバッグ解析を容易にするために、常に"-T"オプションを使用します。

-f "<Filter>"

オプションです。

キャプチャする接続とパケットを指定します。

詳細については、次を参照：カーネルデバッグフィルタ）も参照。

重要 - フィルタを指定しない場合、ツールはすべてのトラフィックのデバッグメッセージを表示します。そのため、CPUに高い負荷がかかり、デバッグ出力ファイルのフォーマット時間が長くなってしまいます。

各フィルタには、次の5つの数値（5-tuple）をカンマで区切って記述する必要があります。

"<Source IP Address>,<Source Port>,<Destination IP Address>,<Destination Port>,<Protocol Number>"

IP 192.168.20.30 から任意のポート、IP 172.16.40.50 からポート 22 へのトラフィックをTCPプロトコルでキャプチャする例：

-f "192.168.20.30,0,172.16.40.50,22,6"

注：

このツールは、最大5つのフィルタに対応しています。
このツールでは、値0（ゼロ）は"any（任意）"となります。
2つ以上のフィルタを指定した場合、ツールは各パケットに対してすべてのフィルタの論理的な「OR」を実行します。

パケットが少なくとも1つのフィルタに一致する場合、ツールはこのパケットのデバッグメッセージを表示します。
"<Source IP Address>"と"<Destination IP Address>" - IPv4 アドレスまたは IPv6 アドレス。
"<Source Port>" および "<Destination Port>" - 1 から 65535 までの整数 (IANA Service Name and Port Number Registry)
<Protocol Number>- 0 から 254 までの整数 (IANA Protocol Numbers)

-o /<Path>/<Name of Raw Debug Output File>

必須です。

生デバッグ出力ファイルの絶対パスとファイル名を指定します。

例:

-o /var/log/kernel_debug.txt

-o /<Path>/<Name of Formatted Debug Output File>

必須です。

フォーマットされたデバッグ出力ファイルの絶対パスとファイル名を指定します（管理者が解析するため）。

例:

-o /var/log/kernel_debug_formatted.txt

手順

重要 - クラスタでは、すべてのクラスタメンバでこれらのステップを同じように実行する必要があります。

セキュリティゲートウェイ/各クラスタメンバ/Scalable Platformセキュリティグループのコマンドラインに接続します。

SSHまたはコンソール接続を使用します。

ベストプラクティス - コンソール接続を使用します。

Scalable Platformの注意点:

SSHで接続する場合は、該当するSecurity Groupに接続する必要があります。
シリアルコンソールで接続する場合は、SMO（Single Management Object）として動作するセキュリティグループメンバに接続する必要があります。

該当するカーネルモジュールで該当するデバッグフラグを有効にする

セキュリティゲートウェイ/各クラスタメンバで、次を実行します。

fw ctl debug -m <module> {all | + <flags>}

Scalable Platformセキュリティグループで、次を実行します。

g_fw ctl debug -m <module> {all | + <flags>}

指定されたカーネルモジュールで有効になっているデバッグフラグのリストを調べる

セキュリティゲートウェイ/各クラスタメンバで、次を実行します。

fw ctl debug -m <module>

Scalable Platformセキュリティグループで、次を実行します。

g_fw ctl debug -m <module>

デバッグキャプチャの開始

セキュリティゲートウェイ/各クラスタメンバで、次を実行します。

conn_life_cycle.sh -a start -o /var/log/kernel_debug.txt -T -f "<Filter1>" [... [-f "<FilterN>"]]

Scalable Platformセキュリティグループで、次を実行します。

g_all conn_life_cycle.sh -a start -o /var/log/kernel_debug.txt -T -f "<Filter1>" [... [-f "<FilterN>"]]

問題を複製するか、問題の発生を待つ

方法がわかっている場合は問題を再現し、そうでなければ問題が発生するのを待ちます。

デバッグキャプチャを停止し、フォーマットされたデバッグ出力を準備する

セキュリティゲートウェイ/各クラスタメンバで、次を実行します。

conn_life_cycle.sh -a stop -o /var/log/kernel_debug_formatted.txt

Scalable Platformセキュリティグループで、次を実行します。

g_all conn_life_cycle.sh -a stop -o /var/log/kernel_debug_formatted.txt

出力ファイルをコンピュータに転送する

このファイルをセキュリティゲートウェイ/各クラスタメンバ/各セキュリティグループメンバからコンピュータに転送します。

/var/log/kernel_debug.txt

ベストプラクティス - このファイルを"tar -zxvf"コマンドで圧縮し、セキュリティゲートウェイ/各クラスタメンバ/各セキュリティグループメンバからコンピュータに転送します。FTPサーバに転送する場合は、バイナリモードで行います。

コンピュータで出力ファイルを分析する

フォーマットされたデバッグ出力ファイルを、Notepad++ (Language > R > Rubyをクリック) などの高度なテキストエディタや、その他のRuby言語ビューアで調べます。

例

IP 172.20.168.15（任意のポート）からIP 192.168.3.53およびポート22へのTCP接続に対するカーネルデバッグの収集

[Expert@GW:0]# fw ctl debug -m fw + conn drop 
Updated kernel's debug variable for module fw 
Debug flags updated. 
[Expert@GW:0]# 
[Expert@GW:0]# fw ctl debug -m fw 
Kernel debugging buffer size: 50KB 
HOST: 
Module: fw 
Enabled Kernel debugging options: error warning conn drop 
Messaging threshold set to type=Info freq=Common 
[Expert@GW:0]# 
[Expert@GW:0]# conn_life_cycle.sh -a start -o /var/log/kernel_debug.txt -T -f "172.20.168.15,0,192.168.3.53,22,6" 
Set operation succeeded 
Set operation succeeded 
Set operation succeeded 
Set operation succeeded 
Set operation succeeded 
Set operation succeeded 
Set operation succeeded 
Initialized kernel debugging buffer to size 8192K 
Set operation succeeded 
Capturing started... 
[Expert@GW:0]# 
 
... ... Replicate the issue, or wait for the issue to occur ... ...
 
[Expert@GW:0]# 
[Expert@GW:0]# conn_life_cycle.sh -a stop -o /var/log/kernel_debug_formatted.txt 
Set operation succeeded 
Defaulting all kernel debugging options 
Debug state was reset to default. 
Set operation succeeded 
doing unification... 
Openning host debug file /tmp/tmp.KiWmF18217... OK 
New unified debug file: /tmp/tmp.imzMZ18220... OK 
prepare unification 
performing unification 
Done :-) 
doing grouping... 
wrapping connections and packets... 
Some of packets lack description, probably because they were already handled when the feature was enabled. 
[Expert@GW:0]# 
[Expert@GW:0]# fw ctl debug -m fw 
Kernel debugging buffer size: 50KB 
HOST: 
Module: fw 
Enabled Kernel debugging options: error warning 
Messaging threshold set to type=Info freq=Common 
[Expert@GW:0] 
[Expert@GW:0] ls -l /var/log/kernel_debug.* 
-rw-rw---- 1 admin root 40960 Nov 26 13:02 /var/log/kernel_debug.txt 
-rw-rw---- 1 admin root 24406 Nov 26 13:02 /var/log/kernel_debug_formatted.txt 
[Expert@GW:0]

メモ帳++でカーネルデバッグを開く

すべてが折りたたまれた状態：

   Connection with 1st packet already in handling so no conn details

[+]{+++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++

最初の階層を開いて接続を確認：

   Connection with 1st packet already in handling so no conn details

[-]{+++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++

;26Nov2018 13:02:06.736016;[cpu_2];[fw4_1];Packet 0xffff8101ea45e680 is  INBOUND;

[+]{---------------------------------------------------------- packet begins ------------------------------------------------------

2番目の階層を開いてこの接続のパケットを確認：

   Connection with 1st packet already in handling so no conn details
[-]{+++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
;26Nov2018 13:02:06.736016;[cpu_2];[fw4_1];Packet 0xffff8101ea45e680 is  INBOUND;
[-]{---------------------------------------------------------- packet begins ------------------------------------------------------
;26Nov2018 13:02:06.736021;[cpu_2];[fw4_1];Packet 0xffff8101ea45e680 is entering  CHAIN_MODULES_ENTER;
;26Nov2018 13:02:06.736035;[cpu_2];[fw4_1];#fwconn_lookup_cache: conn <dir 0, 172.20.168.15:57821 -> 192.168.3.53:22 IPP 6>;
;26Nov2018 13:02:06.736046;[cpu_2];[fw4_1];#<1c001,44000,2,1e2,0,UUID: 5bfbc2a2-0000-0000-c0-a8-3-35-1-0-0-c0, 1,1,ffffffff,ffffffff,40800,0,80,OPQS:[0,ffffc20033d220f0,0,0,0,0,ffffc20033958648,0,0,0,ffffc200325d57b0,0,0,0,0,0],0,0,0,0,0,0,0,0,0,0,0,0,0,0> 
;26Nov2018 13:02:06.736048;[cpu_2];[fw4_1];CONN LIFE CYCLE: lookup: found;
;26Nov2018 13:02:06.736053;[cpu_2];[fw4_1];Packet 0xffff8101ea45e680 is entering  VM_ENTER;
;26Nov2018 13:02:06.736055;[cpu_2];[fw4_1];#
;26Nov2018 13:02:06.736060;[cpu_2];[fw4_1];#Before VM: <dir 0, 172.20.168.15:57821 -> 192.168.3.53:22 IPP 6> (len=40) TCP flags=0x10 (ACK), seq=686659054, ack=4181122096, data end=686659054 (ifn=1) (first seen) (looked up) ;
;26Nov2018 13:02:06.736068;[cpu_2];[fw4_1];#After  VM: <dir 0, 172.20.168.15:57821 -> 192.168.3.53:22 IPP 6> (len=40) TCP flags=0x10 (ACK), seq=686659054, ack=4181122096, data end=686659054 ;
;26Nov2018 13:02:06.736071;[cpu_2];[fw4_1];#VM Final action=ACCEPT;
;26Nov2018 13:02:06.736072;[cpu_2];[fw4_1];# -----  Stateful VM inbound Completed -----
;26Nov2018 13:02:06.736075;[cpu_2];[fw4_1];Packet 0xffff8101ea45e680 is exiting  VM_EXIT;
;26Nov2018 13:02:06.736081;[cpu_2];[fw4_1];Packet 0xffff8101ea45e680 is entering  POST VM_ENTER;
;26Nov2018 13:02:06.736083;[cpu_2];[fw4_1];#
;26Nov2018 13:02:06.736085;[cpu_2];[fw4_1];#fw_post_vm_chain_handler: (first_seen 32, new_conn 0, is_my_ip 0, is_first_packet 0);
;26Nov2018 13:02:06.736089;[cpu_2];[fw4_1];#Before POST VM: <dir 0, 172.20.168.15:57821 -> 192.168.3.53:22 IPP 6> (len=40) TCP flags=0x10 (ACK), seq=686659054, ack=4181122096, data end=686659054 (ifn=1) (first seen) (looked up) ;
;26Nov2018 13:02:06.736095;[cpu_2];[fw4_1];#After  POST VM: <dir 0, 172.20.168.15:57821 -> 192.168.3.53:22 IPP 6> (len=40) TCP flags=0x10 (ACK), seq=686659054, ack=4181122096, data end=686659054 ;
;26Nov2018 13:02:06.736097;[cpu_2];[fw4_1];#POST VM Final action=ACCEPT;
;26Nov2018 13:02:06.736098;[cpu_2];[fw4_1];# -----  Stateful POST VM inbound Completed -----
;26Nov2018 13:02:06.736101;[cpu_2];[fw4_1];Packet 0xffff8101ea45e680 is exiting  POST VM_EXIT;
;26Nov2018 13:02:06.736104;[cpu_2];[fw4_1];#fwconnoxid_msg_get_cliconn: warning - failed to get connoxid message.;
;26Nov2018 13:02:06.736107;[cpu_2];[fw4_1];Packet 0xffff8101ea45e680 is entering  CPAS_ENTER;
;26Nov2018 13:02:06.736110;[cpu_2];[fw4_1];Packet 0xffff8101ea45e680 is exiting  CPAS_EXIT;
;26Nov2018 13:02:06.736113;[cpu_2];[fw4_1];Packet 0xffff8101ea45e680 is exiting  CHAIN_MODULES_EXIT;
;26Nov2018 13:02:06.736116;[cpu_2];[fw4_1];Packet 0xffff8101ea45e680 is  ACCEPTED;
}
;26Nov2018 13:02:06.770652;[cpu_2];[fw4_1];Packet 0xffff8101ea128580 is  INBOUND;