ASA: logging debug-traceを活用したトラブルシューティング

Taisuke Nakamura · ‎2014-08-05

logging debug-traceコマンドとは
logging debug-traceコマンドの有効化と出力例
Case紹介
Case1： SSHのデバッグと、コンソール出力
Case2：冗長構成の設定同期デバッグと、バッファー保存
Case3： IKEv2デバッグと、シスログサーバ保存
参考情報

logging debug-traceコマンドとは

デバッグはトラブルシューティングにおいて大変有用なツールとなりますが、logging debug-traceコマンドを有効化することで、デバッグメッセージをシスログメッセージとして出力できます。

デバッグのシスログメッセージ出力化は、以下のような様々なメリットがあります。

タイムスタンプの付与
デバッグとシスログの同時出力
出力先の選択 (例：コンソールや、Internal Buffer、シスログサーバ、など)
デバッグのシスログレベルの変更 (例：デバッグをAlertレベルで出力、など)
上記変更に伴う、トラブルシューティングの精度や効率の向上

なお、デバッグの利用は大きなCPU負荷を伴います。事前の検証と、通信影響の少ない時間帯での実施を検討下さい。

デバッグは TelnetやSSHセッションなどから抜けると自動で停止するため、セッション非接続時もデバッグを有効のままにしたい場合は、logging debug-trace persistent コマンドの利用を検討してください。当コマンドは、ASAバージョン 9.5(2)以降で利用可能です。詳しくは、ASA: logging debug-trace persistent コマンドについてを参照してください。

本ドキュメントは、ASAバージョン 8.4(7) をベースに確認、作成しております。

logging debug-traceコマンドの有効化と出力例

デバッグの有効化後に、以下コマンドをグローバルコンフィギュレーションモードで有効化する事で、デバッグをシスログメッセージID 711001として出力できます。当シスログメッセージIDの出力ログレベルはレベル７(Debugging)です。

ASA (config)# logging debug-trace

以下は、デバッグのみ有効時と、logging debug-trace コマンド併用時の、出力の違いです。

デバッグのみ有効時：

!! ICMPデバッグ 有効化
ASA# debug icmp trace                  <------ ICMPデバッグ有効化 

!! ICMPデバッグ コンソール出力確認
ASA# ping 192.168.10.101
Type escape sequence to abort.
Sending 5, 100-byte ICMP Echos to 192.168.10.101, timeout is 2 seconds:
ICMP echo request from 192.168.10.1 to 192.168.10.101 ID=39009 seq=53192 len=72
!ICMP echo reply from 192.168.10.101 to 192.168.10.1 ID=39009 seq=53192 len=72

logging debug-trace コマンド併用時：

!! デバッグをシスログ形式でコンソール出力可に変更
ASA(config)# logging enable            <------ ロギング有効化
ASA(config)# logging timestamp         <------ タイムスタンプ有効化
ASA(config)# logging console debugging <------ コンソールの出力ログレベルをレベル7(Debugging)に
ASA(config)# logging debug-trace       <------ デバッグのシスログメッセージ出力有効化 

!! ICMPデバッグ 有効化ASA(config)# debug icmp trace          <------ ICMPデバッグ有効化 

!! ICMPデバッグ シスログ形式でのコンソール出力確認ASA(config)# ping 192.168.10.101
Type escape sequence to abort.
Sending 5, 100-byte ICMP Echos to 192.168.10.101, timeout is 2 seconds:
Aug 06 2014 08:59:54: %ASA-7-609001: Built local-host identity:192.168.10.1
Aug 06 2014 08:59:54: %ASA-7-609001: Built local-host manage:192.168.10.101
Aug 06 2014 08:59:54: %ASA-6-302020: Built outbound ICMP connection for faddr 192.168.10.101/0 gaddr 192.168.10.1/18915 laddr 192.168.10.1/18915
Aug 06 2014 08:59:54: %ASA-7-711001: ICMP echo request from 192.168.10.1 to 192.168.10.101 ID=18915 seq=11794 len=72
!Aug 06 2014 08:59:54: %ASA-7-711001: ICMP echo reply from 192.168.10.101 to 192.168.10.1 ID=18915 seq=11794 len=72

上記例では、logging debug-traceコマンド併用時のほうが、タイムスタンプがあり、かつ通常シスログメッセージとデバッグのメッセージを同時確認できるため、より調査の効率性と精度の向上を期待できます。

デバッグ調査完了後は、undebug all コマンドで、デバッグを無効化して下さい。

Case紹介

以下に、デバッグのシスログメッセージ出力を活用した、調査ケース例を紹介します。
　　　　　　　　　　　　　　　　　　　

Case1： SSHのデバッグと、コンソール出力

調査要件：

SSH接続のトラブルシューティングの為、SSHのデバッグログメッセージをコンソールに出力したい。出力ログレベルをAlertに変更し、タイムスタンプを付けたい。

設定例:

logging enable
logging timestamp
logging console alert
logging debug-tracelogging message 711001 level alert
debug ssh

動作確認:

!! SSHデバッグ有効化
ciscoasa(config)# debug ssh
INFO: 'logging debug-trace' is enabled. All debug messages are currently being redirected to syslog:711001 and will not appear in any monitor session
debug ssh  enabled at level 1

!! SSHクライアントがASAに接続時
ciscoasa(config)#
Aug 05 2014 11:14:38: %ASA-1-711001: Device ssh opened successfully.
Aug 05 2014 11:14:38: %ASA-1-711001: SSH0: SSH client: IP = '192.168.0.101'  interface # = 2
Aug 05 2014 11:14:38: %ASA-1-711001: SSH: host key initialised
Aug 05 2014 11:14:38: %ASA-1-711001: SSH0: starting SSH control process
Aug 05 2014 11:14:38: %ASA-1-711001: SSH0: Exchanging versions - SSH-2.0-Cisco-1.25
Aug 05 2014 11:14:38: %ASA-1-711001: SSH0: send SSH message: outdata is NULL
Aug 05 2014 11:14:38: %ASA-1-711001:server version string:SSH-2.0-Cisco-1.25
Aug 05 2014 11:14:38: %ASA-1-711001: SSH0: receive SSH message: 83 (83)
Aug 05 2014 11:14:38: %ASA-1-711001: SSH0: client version is - SSH-2.0-TTSSH/2.69 Win32
Aug 05 2014 11:14:38: %ASA-1-711001:client version string:SSH-2.0-TTSSH/2.69 Win32
Aug 05 2014 11:14:38: %ASA-1-711001:SSH2 0: SSH2_MSG_KEXINIT sent
Aug 05 2014 11:14:39: %ASA-1-711001:SSH2 0: SSH2_MSG_KEXINIT received
Aug 05 2014 11:14:39: %ASA-1-711001:SSH2: kex: client->server aes256-cbc hmac-sha1 none
Aug 05 2014 11:14:39: %ASA-1-711001:SSH2: kex: server->client aes256-cbc hmac-sha1 none
Aug 05 2014 11:14:39: %ASA-1-711001:SSH2 0: expecting SSH2_MSG_KEXDH_INIT
Aug 05 2014 11:14:39: %ASA-1-711001:SSH2 0: SSH2_MSG_KEXDH_INIT received
Aug 05 2014 11:14:39: %ASA-1-711001:SSH2 0: signature length 143
Aug 05 2014 11:14:39: %ASA-1-711001:SSH2: kex_derive_keys complete
Aug 05 2014 11:14:39: %ASA-1-711001:SSH2 0: newkeys: mode 1
Aug 05 2014 11:14:39: %ASA-1-711001:SSH2 0: SSH2_MSG_NEWKEYS sent
Aug 05 2014 11:14:39: %ASA-1-711001:SSH2 0: waiting for SSH2_MSG_NEWKEYS
Aug 05 2014 11:14:39: %ASA-1-711001:SSH2 0: newkeys: mode 0
Aug 05 2014 11:14:39: %ASA-1-711001:SSH2 0: SSH2_MSG_NEWKEYS received

!! SSHクライアントがローカル認証成功時
ciscoasa(config)#
Aug 05 2014 11:14:58: %ASA-1-711001: SSH(cisco): user authen method is 'use AAA', aaa server group ID = 1
Aug 05 2014 11:14:58: %ASA-1-711001: SSH(cisco): user authen method is 'use AAA', aaa server group ID = 1
Aug 05 2014 11:14:58: %ASA-1-711001:SSH2 0: authentication successful for cisco
Aug 05 2014 11:14:58: %ASA-1-711001:SSH2 0: channel open request
Aug 05 2014 11:14:58: %ASA-1-711001:SSH2 0: pty-req request
Aug 05 2014 11:14:58: %ASA-1-711001:SSH2 0: requested tty: xterm, height 24, width 80
Aug 05 2014 11:14:58: %ASA-1-711001:SSH2 0: shell request
Aug 05 2014 11:14:58: %ASA-1-711001:SSH2 0: shell message received

補足:
コンソールでの調査は、ログ出力が比較的少量の場合に向きます。調査時のみ有効化し、通常運用時は無効化が推奨です。

Case2：冗長構成の設定同期デバッグと、バッファー保存

調査要件：

マルチコンテキストの冗長構成で、Active機の設定変更時の、Standby機側の設定同期内容を確認したい。 Standby機でデバッグを有効化し、出力ログレベルをAlert、シスログメッセージをロギングバッファに 1Mバイト分格納したい。

設定例:

logging enable
logging timestamp
logging buffer-size 1048576
logging buffered alert
logging debug-tracelogging message 711001 level alert
debug fover sync

動作確認:

!! Active機 - ロギング設定確認
ASA/admin/pri/act# show run logging
logging enable
logging timestamp
logging buffer-size 1048576
logging buffered alerts
logging debug-trace
logging message 711001 level alerts

!! Standby機 - デバッグ有効化  ※デバッグコマンドは同期されません
ASA/sec/stby# debug fover sync
INFO: 'logging debug-trace' is enabled. All debug messages are currently being redirected to syslog:711001 and will not appear in any monitor session
fover event trace on

!! Active機 - 設定変更
ASA/admin/pri/act(config)# int ma 0/1
ASA/admin/pri/act(config-if)# description ## Management02 ##
ASA/admin/pri/act(config-if)# nameif manage02
ASA/admin/pri/act(config-if)# ip address 172.16.10.254 255.255.255.0 standby 172.16.10.253
ASA/admin/pri/act(config-if)# no shut
ASA/admin/pri/act(config-if)# end
ASA/admin/pri/act# write mem

!! Standby機 - ロギングバッファ内のデバッグ ログメッセージの確認
ASA/admin/sec/stby# show log
    <snip>
Aug 05 2014 16:50:06: %ASA-1-711001: fover_parse: parse_thread_helper: Cmd: int ma 0/1
Aug 05 2014 16:50:16: %ASA-1-711001: fover_parse: parse_thread_helper: Cmd: description ## Management02 ##
Aug 05 2014 16:50:45: %ASA-1-711001: fover_parse: parse_thread_helper: Cmd: nameif manage02
Aug 05 2014 16:51:01: %ASA-1-711001: fover_parse: parse_thread_helper: Cmd: ip address 172.16.10.254 255.255.255.0 standby 172.16.10.253
Aug 05 2014 16:51:03: %ASA-1-711001: fover_parse: parse_thread_helper: Cmd: no shut
Aug 05 2014 16:54:49: %ASA-1-711001: fover_parse: parse_thread_helper: Cmd: copy /noconfirm running-config startup-config

補足：
Standby機のロギング出力はデフォルト無効です。デバッグとロギング出力を合わせて確認したい場合は、Active機側で "logging standby"コマンドを有効化してください。詳しくは ASA: 冗長機能と、Failoverのトリガー、Health Monitoringについてを参照してください。

Case3： IKEv2デバッグと、シスログサーバ保存

調査要件：

Preshared Keyを用いた、IKEv2のサイト間VPNの構成で、通常のシスログメッセージ(informationalレベル以上)と、IKEv2のデバッグメッセージを同時に取得したい。各メッセージは、指定の外部シスログサーバに保存したい。

設定例:

logging enable
logging timestamp
logging trap informational
logging host [Interface名] [SyslogサーバIP]
logging debug-tracelogging message 711001 level informational
debug crypto ikev2 protocol 127
debug crypto ikev2 platform 127

動作確認:

!! 本社側ASA - ロギング設定状況 確認 
ASA-HQ01(config)# sh run logging
logging enable
logging timestamp
logging trap informational
logging host manage 192.168.0.101
logging debug-trace
logging message 711001 level informational

!! 本社側ASA - IKEv2 デバッグ有効化
ASA-HQ01(config)# debug crypto ikev2 protocol 127
INFO: 'logging debug-trace' is enabled. All debug messages are currently being redirected to syslog:711001 and will not appear in any monitor session
ASA-HQ01(config)# debug crypto ikev2 platform 127
INFO: 'logging debug-trace' is enabled. All debug messages are currently being redirected to syslog:711001 and will not appear in any monitor session
ASA-HQ01(config)# sh debug
debug crypto ikev2 protocol enabled at level 127
debug crypto ikev2 platform enabled at level 127

!! 本社側ASA - IKEv2 SA状態確認 
ASA-HQ01# sh cry ikev2 sa
  There are no IKEv2 SAs

!!支社側端末から、本社側端末にPING   
      
          　　
!! 本社側ASA - IKEv2 SA状態確認
ASA-HQ01# sh cry ikev2 sa
IKEv2 SAs:
Session-id:1, Status:UP-ACTIVE, IKE count:1, CHILD count:1
Tunnel-id                 Local                Remote     Status         Role
  3973227          10.0.0.1/500          10.0.0.2/500      READY    INITIATOR
      Encr: 3DES, Hash: MD596, DH Grp:2, Auth sign: PSK, Auth verify: PSK
      Life/Active Time: 86400/15 sec
Child sa: local selector  192.168.0.0/0 - 192.168.0.255/65535
          remote selector 192.168.10.0/0 - 192.168.10.255/65535
          ESP spi in/out: 0x9298798c/0x9c426600


!! 外部シスログサーバで 各メッセージの受信確認