UDLDを究める:(15) UDLD のデバッグ (1) ネイバー関係の確立

debug コマンドを使って、ポートがリンク・アップしてからBi-directional となるまでの流れを見ていきます。

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


Catalyst-A

リンク・アップしました。

*Mar  5 22:04:53: UDLD send probe message, flags = rec_timeout | resynch (Gi0/11)
*Mar 5 22:04:53: Pr (Gi0/11)
*Mar 5 22:04:54: UDLD send probe message, flags = rec_timeout | resynch (Gi0/11)
*Mar 5 22:04:54: Pr (Gi0/11)
*Mar 5 22:04:55: UDLD send probe message, flags = rec_timeout | resynch (Gi0/11)
*Mar 5 22:04:55: Pr (Gi0/11)
*Mar 5 22:04:56: UDLD send probe message, flags = rec_timeout | resynch (Gi0/11)
*Mar 5 22:04:56: Pr (Gi0/11)
*Mar 5 22:04:57: UDLD send probe message, flags = rec_timeout | resynch (Gi0/11)
*Mar 5 22:04:57: Pr (Gi0/11)
*Mar 5 22:04:58: UDLD send probe message, flags = rec_timeout | resynch (Gi0/11)
*Mar 5 22:04:58: Pr (Gi0/11)
*Mar 5 22:04:59: UDLD send probe message, flags = rec_timeout | resynch (Gi0/11)
*Mar 5 22:04:59: Pr (Gi0/11)
*Mar 5 22:05:00: UDLD send probe message, flags = rec_timeout | resynch (Gis0/11)
*Mar 5 22:05:00: Pr (Gi0/11)

① 1 秒間隔でProbe を送信しています。 Recommended Timeout とReSynch フラグがセットされています。Pr はProbe を意味します。

*Mar  5 22:05:01: UDLD send probe message, flags = rec_timeout (Gi0/11)
*Mar 5 22:05:01: P (Gi0/11)
*Mar 5 22:05:08: UDLD send probe message, flags = rec_timeout (Gi0/11)
*Mar 5 22:05:08: P (Gi0/11)
*Mar 5 22:05:15: UDLD send probe message, flags = rec_timeout (Gi0/11)
*Mar 5 22:05:15: P (Gi0/11)
*Mar 5 22:05:22: UDLD send probe message, flags = rec_timeout (Gi0/11)
*Mar 5 22:05:22: P (Gi0/11)
*Mar 5 22:05:29: UDLD send probe message, flags = rec_timeout (Gi0/11)
*Mar 5 22:05:29: P (Gi0/11)
*Mar 5 22:05:36: UDLD send probe message, flags = rec_timeout (Gi0/11)
*Mar 5 22:05:36: P (Gi0/11)
*Mar 5 22:05:43: UDLD send probe message, flags = rec_timeout (Gi0/11)

② 8秒経過すると、以後のProbe はRe-Synch フラグをリセットし、7秒間隔で送信されます。
 
*Mar  5 22:06:49: udld process packet received, length 99 (Gi0/11) 
*Mar 5 22:06:49: 21 01 62 47 00 01 00 0F 43 48 4B 30 36 31 39 57 30 4D 55 00
*Mar 5 22:06:49: 02 00 0A 47 69 30 2F 31 32 00 03 00 08 00 00 00 00 00 04 00
*Mar 5 22:06:49: 05 07 00 05 00 05 05 00 06 00 16 43 61 74 61 6C 79 73 74 33
*Mar 5 22:06:49: 35 35 30 2D 31 32 54 3A 43 00 07 00 08 00 00 00 05
*Mar 5 22:06:49: TLV = 1 TLV length = 15 (Gi0/11)
*Mar 5 22:06:49: item_len[1] = 12 (Gi0/11)
*Mar 5 22:06:49: Bytes left = 58 (Gi0/11)
*Mar 5 22:06:49: TLV = 2 TLV length = 10 (Gi0/11)
*Mar 5 22:06:49: item_len[2] = 7 (Gi0/11)
*Mar 5 22:06:49: Bytes left = 48 (Gi0/11)
*Mar 5 22:06:49: TLV = 3 TLV length = 8 (Gi0/11)
*Mar 5 22:06:49: Bytes left = 40 (Gi0/11)
*Mar 5 22:06:49: TLV = 4 TLV length = 5 (Gi0/11)
*Mar 5 22:06:49: item_len[4] = 1 (Gi0/11)
*Mar 5 22:06:49: Bytes left = 35 (Gi0/11)
*Mar 5 22:06:49: TLV = 5 TLV length = 5 (Gi0/11)
*Mar 5 22:06:49: item_len[5] = 1 (Gi0/11)
*Mar 5 22:06:49: Bytes left = 30 (Gi0/11)
*Mar 5 22:06:49: TLV = 6 TLV length = 22 (Gi0/11)
*Mar 5 22:06:49: item_len[6] = 19 (Gi0/11)
*Mar 5 22:06:49: Bytes left = 8 (Gi0/11)
*Mar 5 22:06:49: TLV = 7 TLV length = 8 (Gi0/11)
*Mar 5 22:06:49: item_len[7] = 4 (Gi0/11)
*Mar 5 22:06:49: Bytes left = 0 (Gi0/11)
*Mar 5 22:06:49: Parse packet info and insert entry (0xD8BA50) into cache. (Gi0/11)
*Mar 5 22:06:49: Cached TLV #1 = CHK0619W0MU, length = 11 (Gi0/11)
*Mar 5 22:06:49: Cached TLV #2 = Gi0/12, length = 6 (Gi0/11)
*Mar 5 22:06:49: udld_handle_bidirdetect_info (Gi0/11)
*Mar 5 22:06:49: udld_handle_bidirdetect_info pairs = 0 (Gi0/11)
*Mar 5 22:06:49: Cached TLV #4 = 7, length = 0 (Gi0/11)
*Mar 5 22:06:49: Cached TLV #5 = 5, length = 0 (Gi0/11)
*Mar 5 22:06:49: Cached TLV #6 = Catalyst3550-12T:C, length = 18 (Gi0/11)
*Mar 5 22:06:49: Cached TLV #7, val = 3 length = 5 (Gi0/11)
*Mar 5 22:06:49: New_entry = D8BA50 (Gi0/11)
*Mar 5 22:06:49: Device Index = 1 (Gi0/11)
*Mar 5 22:06:49: First entry (Gi0/11)
*Mar 5 22:06:49: Probe packet (Gi0/11)
*Mar 5 22:06:49: Zero IDs in 2way conn list (Gi0/11)
*Mar 5 22:06:49: Non-RSY new neighbor (Gi0/11)
*Mar 5 22:06:49: Udld entering detection phase. (Gi0/11)
*Mar 5 22:06:49: UDLD send echo message, flags = 0 (Gi0/11)
*Mar 5 22:06:49: E (Gi0/11)

③ 対向機器からのUDLD PDU をGigabitEthernet0/11 で受信しました。
④ Echo TLV は空です(16 進数の赤い部分)。
⑤ ここまでが一つのUDLD PDU です。E はEcho を意味します。
 
*Mar  5 22:06:49: Zero IDs in 2way conn list (Gi0/11)
*Mar 5 22:06:49: Zero IDs in 2way conn list (Gi0/11)
*Mar 5 22:06:49: UDLD FSM updated port, bi-flag udld_empty_echo, phase udld_detection (Gi0/11)

⑥ Detection フェイズへ移行します。
 
*Mar  5 22:06:49: Udld receive packet *END*.  (Gi0/11)
*Mar 5 22:06:49: udld process packet received, length 120 (Gi0/11)
*Mar 5 22:06:49: 22 00 C9 95 00 01 00 0F 43 48 4B 30 36 31 39 57 30 4D 55 00
*Mar 5 22:06:49: 02 00 0A 47 69 30 2F 31 32 00 03 00 1D 00 00 00 01 00 0B 46
*Mar 5 22:06:49: 41 41 30 35 34 39 53 30 41 54 00 06 47 69 30 2F 31 31 00 04
*Mar 5 22:06:49: 00 05 07 00 05 00 05 05 00 06 00 16 43 61 74 61 6C 79 73 74
*Mar 5 22:06:49: 33 35 35 30 2D 31 32 54 3A 43 00 07 00 08 00 00 00 01
*Mar 5 22:06:49: TLV = 1 TLV length = 15 (Gi0/11)
*Mar 5 22:06:49: item_len[1] = 12 (Gi0/11)
*Mar 5 22:06:49: Bytes left = 79 (Gi0/11)
*Mar 5 22:06:49: TLV = 2 TLV length = 10 (Gi0/11)
*Mar 5 22:06:49: item_len[2] = 7 (Gi0/11)
*Mar 5 22:06:49: Bytes left = 69 (Gi0/11)
*Mar 5 22:06:49: TLV = 3 TLV length = 29 (Gi0/11)
*Mar 5 22:06:49: Bytes left = 40 (Gi0/11)
*Mar 5 22:06:49: TLV = 4 TLV length = 5 (Gi0/11)
*Mar 5 22:06:49: item_len[4] = 1 (Gi0/11)
*Mar 5 22:06:49: Bytes left = 35 (Gi0/11)
*Mar 5 22:06:49: TLV = 5 TLV length = 5 (Gi0/11)
*Mar 5 22:06:49: item_len[5] = 1 (Gi0/11)
*Mar 5 22:06:49: Bytes left = 30 (Gi0/11)
*Mar 5 22:06:49: TLV = 6 TLV length = 22 (Gi0/11)
*Mar 5 22:06:49: item_len[6] = 19 (Gi0/11)
*Mar 5 22:06:49: Bytes left = 8 (Gi0/11)
*Mar 5 22:06:49: TLV = 7 TLV length = 8 (Gi0/11)
*Mar 5 22:06:49: item_len[7] = 4 (Gi0/11)
*Mar 5 22:06:49: Bytes left = 0 (Gi0/11)
*Mar 5 22:06:49: Parse packet info and insert entry (0x1141168) into cache. (Gi0/11)
*Mar 5 22:06:49: Cached TLV #1 = CHK0619W0MU, length = 11 (Gi0/11)
*Mar 5 22:06:49: Cached TLV #2 = Gi0/12, length = 6 (Gi0/11)
*Mar 5 22:06:49: udld_handle_bidirdetect_info (Gi0/11)
*Mar 5 22:06:49: udld_handle_bidirdetect_info pair left = 1 (Gi0/11)
*Mar 5 22:06:49: FAA0549S0AT device (Gi0/11)
*Mar 5 22:06:49: udld_handle_bidirdetect_info: good packet (Gi0/11)
*Mar 5 22:06:49: Cached TLV #4 = 7, length = 0 (Gi0/11)
*Mar 5 22:06:49: Cached TLV #5 = 5, length = 0 (Gi0/11)
*Mar 5 22:06:49: Cached TLV #6 = Catalyst3550-12T:C, length = 18 (Gi0/11)
*Mar 5 22:06:49: Cached TLV #7, val = 3 length = 1 (Gi0/11)
*Mar 5 22:06:49: New_entry = 1141168 (Gi0/11)
*Mar 5 22:06:49: Found an entry from same device (Gi0/11)
*Mar 5 22:06:49: Cached entries = 2 (Gi0/11)
*Mar 5 22:06:49: Entry (0xD8BA50) deleted: 1 entries cached
*Mar 5 22:06:49: Cached entries = 1 (Gi0/11)
*Mar 5 22:06:49: Echo packet (Gi0/11)
*Mar 5 22:06:49: Checking if multiple neighbors (Gi0/11)
*Mar 5 22:06:49: Single neighbor detected (Gi0/11)
*Mar 5 22:06:49: Checking if link is bidirectional (Gi0/11)
*Mar 5 22:06:49: Found my own ID pair in 2way conn list (Gi0/11)
*Mar 5 22:06:49: Checking if multiple neighbors (Gi0/11)
*Mar 5 22:06:49: Single neighbor detected (Gi0/11)
*Mar 5 22:06:49: Checking if link is bidirectional (Gi0/11)
*Mar 5 22:06:49: Found my own ID pair in 2way conn list (Gi0/11)
*Mar 5 22:06:49: UDLD FSM updated port, bi-flag udld_bidir_detected, phase udld_detection (Gi0/11)
*Mar 5 22:06:49: Udld receive packet *END*. (Gi0/11)
*Mar 5 22:06:50: timeout timer = 4 (Gi0/11)
*Mar 5 22:06:50: UDLD send echo message, flags = 0 (Gi0/11)
*Mar 5 22:06:50: E (Gi0/11)

⑦ 次のUDLD PDU を受信しました。Echo TLV から、対向機器が自分のUDLD PDU を受信できていることがわかります(対向機器もDetection フェイズへ移行しています)。Message Interval は7 になっています(16 進数の緑色の部分)。

⑧ ここまでが一つのUDLD PDU です。E はEcho を意味します。

⑨ Bi-directional になりました。
 
*Mar  5 22:06:54: Phase set to udld_advertisement from phase udld_detection. (Gi0/11)
*Mar 5 22:06:54: Phase set to udld_advertisement after timer_expired. (Gi0/11)

⑩ Advertisement フェイズへ移行します。