UDLDを究める:(16) UDLD のデバッグ (2) Unidirectional(片方向)を検知する(ノーマル・モード)

debug コマンドを使って、Unidirectional を検知してから、ErrDisable されるまでの流れを見ていきます。

a
Catalyst のコンソールで、debug udld events とdebug udld packets コマンドを実行します。

Catalyst#debug udld events
UDLD events debugging is on
Catalyst#debug udld packets
UDLD packets debugging is on
Catalyst#






出力されるログ中の色付けされた16進数は、以下のとおりです。

    Device ID
    Port ID
    Echo
    Message Interval
    Flags


Catalyst-A

Bi-directional(双方向)になっています。

*Mar 17 03:56:00: allNeighborsAgedOutEvent during link up. (Gi0/11) 
*Mar 17 03:56:00: Phase set from ADV to LUP because all neighbors aged out (Gi0/11)
*Mar 17 03:56:00: UDLD send probe message, flags = rec_timeout | resynch (Gi0/11)
*Mar 17 03:56:00: Pr (Gi0/11)
*Mar 17 03:56:00: prev = 0 entry = 1141168 next = 0 exp_time = 0 (Gi0/11)
*Mar 17 03:56:00: udsb->cache = 0xDCA128 (Gi0/11)
*Mar 17 03:56:00: timeout timer = 7 (Gi0/11)
*Mar 17 03:56:00: UDLD send probe message, flags = rec_timeout | resynch (Gi0/11)
*Mar 17 03:56:00: Pr (Gi0/11)
*Mar 17 03:56:01: timeout timer = 6 (Gi0/11)
*Mar 17 03:56:01: UDLD send probe message, flags = rec_timeout | resynch (Gi0/11)
*Mar 17 03:56:01: Pr (Gi0/11)
*Mar 17 03:56:02: timeout timer = 5 (Gi0/11)
*Mar 17 03:56:02: UDLD send probe message, flags = rec_timeout | resynch (Gi0/11)
*Mar 17 03:56:02: Pr (Gi0/11)

① 対向機器からUDLD PDU を受信しなくなり、エントリーをテーブルから消去しました。
② Link Up フェイズへ移行しました。
③ 空のEcho TLV を持ったProbe を送信し始めます。 Recommended Timeout フラグとReSynch フラグが立っています。



Catalyst-B

*Mar 17 03:56:00: udld process packet received, length 99 (Gi0/12) 
*Mar 17 03:56:00: 21 03 6E 0A 00 01 00 0F 46 41 41 30 35 34 39 53 30 41 54 00
*Mar 17 03:56:00: 02 00 0A 47 69 30 2F 31 31 00 03 00 08 00 00 00 00 00 04 00
*Mar 17 03:56:00: 05 07 00 05 00 05 05 00 06 00 16 43 61 74 61 6C 79 73 74 33
*Mar 17 03:56:00: 35 35 30 2D 31 32 54 3A 41 00 07 00 08 00 00 00 54
*Mar 17 03:56:00: TLV = 1 TLV length = 15 (Gi0/12)
*Mar 17 03:56:00: item_len[1] = 12 (Gi0/12)
*Mar 17 03:56:00: Bytes left = 58 (Gi0/12)
*Mar 17 03:56:00: TLV = 2 TLV length = 10 (Gi0/12)
*Mar 17 03:56:00: item_len[2] = 7 (Gi0/12)
*Mar 17 03:56:00: Bytes left = 48 (Gi0/12)
*Mar 17 03:56:00: TLV = 3 TLV length = 8 (Gi0/12)
*Mar 17 03:56:00: Bytes left = 40 (Gi0/12)
*Mar 17 03:56:00: TLV = 4 TLV length = 5 (Gi0/12)
*Mar 17 03:56:00: item_len[4] = 1 (Gi0/12)
*Mar 17 03:56:00: Bytes left = 35 (Gi0/12)
*Mar 17 03:56:00: TLV = 5 TLV length = 5 (Gi0/12)
*Mar 17 03:56:00: item_len[5] = 1 (Gi0/12)
*Mar 17 03:56:00: Bytes left = 30 (Gi0/12)
*Mar 17 03:56:00: TLV = 6 TLV length = 22 (Gi0/12)
*Mar 17 03:56:00: item_len[6] = 19 (Gi0/12)
*Mar 17 03:56:00: Bytes left = 8 (Gi0/12)
*Mar 17 03:56:00: TLV = 7 TLV length = 8 (Gi0/12)
*Mar 17 03:56:00: item_len[7] = 4 (Gi0/12)
*Mar 17 03:56:00: Bytes left = 0 (Gi0/12)
*Mar 17 03:56:00: Parse packet info and insert entry (0xDB6840) into cache. (Gi0/12)
*Mar 17 03:56:00: Cached TLV #1 = FAA0549S0AT, length = 11 (Gi0/12)
*Mar 17 03:56:00: Cached TLV #2 = Gi0/11, length = 6 (Gi0/12)
*Mar 17 03:56:00: udld_handle_bidirdetect_info (Gi0/12)
*Mar 17 03:56:00: udld_handle_bidirdetect_info pairs = 0 (Gi0/12)
*Mar 17 03:56:00: Cached TLV #4 = 7, length = 0 (Gi0/12)
*Mar 17 03:56:00: Cached TLV #5 = 5, length = 0 (Gi0/12)
*Mar 17 03:56:00: Cached TLV #6 = Catalyst3550-12T:A, length = 18 (Gi0/12)
*Mar 17 03:56:00: Cached TLV #7, val = 3 length = 84 (Gi0/12)
*Mar 17 03:56:00: New_entry = DB6840 (Gi0/12)
*Mar 17 03:56:00: Found an entry from same device (Gi0/12)
*Mar 17 03:56:00: Cached entries = 2 (Gi0/12)
*Mar 17 03:56:00: Entry (0xDA873C) deleted: 1 entries cached
*Mar 17 03:56:00: Cached entries = 1 (Gi0/12)
*Mar 17 03:56:00: Probe packet(resynch) (Gi0/12)
*Mar 17 03:56:00: Zero IDs in 2way conn list (Gi0/12)
*Mar 17 03:56:00: Doing neighbor scanning after bidir->non-bidir transition. (Gi0/12)
*Mar 17 03:56:00: Bidir->all unidir => DET. (Gi0/12)
*Mar 17 03:56:00: RSY neighbor (Gi0/12)
*Mar 17 03:56:00: Udld entering detection phase. (Gi0/12)
*Mar 17 03:56:00: UDLD send echo message, flags = 0 (Gi0/12)
*Mar 17 03:56:00: E (Gi0/12)
*Mar 17 03:56:00: Zero IDs in 2way conn list (Gi0/12)
*Mar 17 03:56:00: Zero IDs in 2way conn list (Gi0/12)
*Mar 17 03:56:00: UDLD FSM updated port, bi-flag udld_empty_echo, phase udld_detection (Gi0/12)
*Mar 17 03:56:00: Udld receive packet *END*. (Gi0/12)

④ Catalyst-A からのUDLD PDU(Echo TLV が空)を、GigabitEthernet0/12 で受信しました(Catalyst-A ログの③のフレームです。Recommended Timeout フラグとReSynch フラグが立っています。

⑤ ここまでが一つのUDLD PDU です。
⑥ Detection フェイズへ移行しました。
 
*Mar 17 03:56:05: confirmation recv'd in EXT (Gi0/12) 
*Mar 17 03:56:05: UDLD disabled port, packet received in extended detection (Gi0/12)
*Mar 17 03:56:05: UDLD send flush message, flags = 0 (Gi0/12)
*Mar 17 03:56:05: F (Gi0/12)
*Mar 17 03:56:05: %UDLD-4-UDLD_PORT_DISABLED: UDLD disabled interface Gi0/12, unidirectional link detected
*Mar 17 03:56:05: %PM-4-ERR_DISABLE: udld error detected on Gi0/12, putting Gi0/12 in err-disable state
*Mar 17 03:56:05: Port UDLD set error disabled (Gi0/12)
*Mar 17 03:56:05: Entry (0xDB6840) deleted: 0 entries cached
*Mar 17 03:56:05: Hash entry deleted = DB6840 (Gi0/12)
*Mar 17 03:56:05: current phase = udld_disable_port (Gi0/12)
*Mar 17 03:56:05: Restart counter = 0 (Gi0/12)
*Mar 17 03:56:05: Neighbors counter = 0 (Gi0/12)
*Mar 17 03:56:05: Udld receive packet *END*. (Gi0/12)
*Mar 17 03:56:19: %LINEPROTO-5-UPDOWN: Line protocol on Interface GigabitEthernet0/12, changed state to down
*Mar 17 03:56:19: %LINEPROTO-5-UPDOWN: Line protocol on Interface Vlan1, changed state to down
*Mar 17 03:56:20: %LINK-3-UPDOWN: Interface GigabitEthernet0/12, changed state to down

⑦ 拡張ディテクション・ウィンドウが始まった直後に、空のEcho TLV を持ったProbe を受信しました。
⑧ Flush を送信しました。 F はFlush を意味します。
⑨ GigabitEthernet0/12 をErrDisable にしました。