<概要>
Catalyst製品でCPU使用率が一時的に短時間上昇する様なケースや、不定期に発生する様なケースで、"process cpu threshold" を設定し、CPU 使用率が上昇した際にメッセージ出力を行う事や、EEM を設定する事で、CPU 使用率が一時的に上昇している際に効率的にログ取得を行う事が可能です。
<背景>
CPU 使用率が上昇する様なケースのトラブルシューティングを行う場合、CPU 使用率が上昇している際にログ取得を行う必要があります。
CPU 使用率が上昇する時間帯が特定の時間帯である場合や、比較的長い間、使用率が高い状況が継続するといったケースでは、CPU 使用率が上昇している際にログ取得を行う事は比較的容易ですが、CPU 使用率が上昇している期間が短期間である場合や、不定期に発生する場合等、CPU 使用率が上昇している際にログ取得を行う事が困難な場合があります。
<具体的な設定例 1>
"process cpu threshold" コマンドを使用する事により、CPU 使用率が指定した値に達した場合、メッセージを出力させる事ができます。
メッセージの出力には、合計の CPU 使用率、割り込みによる使用率、使用率がもっとも高い3つのプロセスの PID と、その使用率が表示されるので、どの様なプロセスにより CPU 使用率が上昇しているのかを確認する事ができます。
以下の設定例では、トータルの CPU 使用率が、90 パーセント以上となった場合にロギングが行われます。
インターバルは5秒です。
設定はグローバルコンフィギュレーションモードで行います。
---------------設定例-----------------
process cpu threshold type total rising 90 interval 5
------------------------------------------
<設定例 1で取得した情報>
以下は上記の設定を行った際の、実際の出力例です。
--------------------ログ出力例-------------------
Apr 18 23:07:15 JST: %SYS-1-CPURISINGTHRESHOLD: Threshold: Total CPU Utilization(Total/Intr): 95%/2%, Top 3 processes(Pid/Util): 374/70%, 169/6%, 85/1%
--------------------------------------------------
この例では、CPU 使用率の合計が 95 パーセント、割り込みの使用率が 2 パーセント、PID 374 の使用率が 70 パーセント、PID 169 の使用率が 6 パーセント、PID 85 の使用率が 1 パーセントとなっています。
各 PID がどのプロセスを示しているかは、該当システムで、"show processes cpu" 等を使用しで確認します。
この例のシステムでは、PID 374 は SNMP ENGINE であり、該当システムによる SNMP トラップの送信や、管理システムからの SNMP ポーリングに起因して CPU 使用率が上昇している可能性が考えられます。
<具体的な設定例 2>
"process cpu threshold" によるメッセージ出力や、CPU 使用率を取得できる OID をトリガに使用し、各ログ取得を行う EEM を設定する事ができます。
以下は、"process cpu threshold" コマンドによるメッセージをトリガとして、各ログ取得を行うEEM の設定例です。
この様な設定を行う事で、さらに詳しいトラブルシューティングを行う事ができます。
どの様なログを取得すべきかという点に関しては、割り込みにより上昇しているのかプロセスによって上昇しているのか、プロセスにより上昇している場合、どのプロセスによって上昇しているのかにより異なります。
例えば、ルーティング関連のプロセスによる CPU 使用率の上昇といったケースでは、該当プロトコルに関連したログ取得が必要となりますし、割り込みにより CPU 使用率が上昇している場合は、H/W転送に何らかの問題が発生しているという事を想定したログ取得が必要になる等、ケースバイケースとなります。
この設定例では、SNMP ENGINE の使用率が高い事を想定しています。
---------------設定例-----------------
event manager applet DETECT_HIGH_CPU
event syslog pattern "SYS-1-CPURISINGTHRESHOLD"
action 1 cli command "enable"
action 2 cli command "show stacks 374 | redirect flash:stacks.txt"
action 3 cli command "show processes cpu sorted | redirect flash:sorted.txt"
action 4 cli command "show stacks 374 | redirect flash:stacks2.txt"
action 5 cli command "show processes cpu history | redirect flash:history.txt"
------------------------------------------
上記の例は、"process cpu threshold" コマンドによる "%SYS-1-CPURISINGTHRESHOLD" 出力をトリガとして、SNMP ENGIN プロセスによるCPU使用率が高い事を想定し、以下のログ取得を行う設定です。
※show stacks は意図的に2度取得しています
---------------取得コマンド--------------
show stacks <PID>
show processes cpu sorted
show stacks <PID>
show processes cpu history
------------------------------------------
この例では、各コマンド出力は、それぞれ以下の名前で flash に保存されます。
---------作成されるファイル-------------
stacks.txt
sorted.txt
stacks2.txt
history.txt
------------------------------------------
<設定例 2で取得した情報>
以下は、実際に上記の設定で取得したログの一部です。
--------------ログ出力例 1---------------
Switch#more flash:sorted.txt
CPU utilization for five seconds: 99%/1%; one minute: 46%; five minutes: 41%
PID Runtime(ms) Invoked uSecs 5Sec 1Min 5Min TTY Process
374 790787 50397 15691 71.58% 7.80% 1.64% 0 SNMP ENGINE
上記の出力から、CPU使用率合計が99パーセントで、その内の71パーセントが SNMP ENGINE プロセスによるものであり、該当システムによる SNMP トラップの送信や、管理システムからの SNMP ポーリングに起因して CPU 使用率が上昇している可能性が考えられます。
--------------ログ出力例 2---------------
Switch#more flash:stack.txt
Process 374: SNMP ENGINE
Stack segment 0x7363F50 - 0x7366E30
FP: 0x73669F8, RA: 0x1A8242C
FP: 0x7366A00, RA: 0xCD4B8
FP: 0x7366A30, RA: 0xDCCC0
FP: 0x7366A68, RA: 0xDCE20
FP: 0x7366A88, RA: 0xDD500
FP: 0x7366AA8, RA: 0xD7230
FP: 0x7366B58, RA: 0xE39C4
FP: 0x7366B90, RA: 0xDE4B04
FP: 0x7366C00, RA: 0xDE1000
FP: 0x7366C38, RA: 0x17B6DA8
FP: 0x7366C58, RA: 0x17B7030
FP: 0x7366CA8, RA: 0x17B5CCC
FP: 0x7366D10, RA: 0x1788D10
FP: 0x7366D98, RA: 0x17791D0
FP: 0x7366E20, RA: 0x17A41B8
FP: 0x7366E28, RA: 0x26D5768
FP: 0x0, RA: 0x26CF5DC
上記出力を解析すると、CPU使用率が上昇していた際、他のノードから ipNetToMediaEntry がポーリングされ、システムはそれに応答するための処理を行っていた事が分かります。
この例では、 ipNetToMediaEntry をSNMP View で Exclude する事により、CPU使用率の上昇を防げる事が予想されます。
