Авария: отказал CEF на Cisco 6500

Разберём на будущее случай с аварией, когда отказал CEF на Cisco 6500

Пришла sms, что такой-то маршрутизатор (Cisco 6500) UP. Поясню, что система мониторинга просто пингует маршрутизатор и сообщает, если изменилось его состояние: DOWN/UP. Это очень опасная sms, т.к. каждый такой маршрутизатор — как микрорайон или его половина (дело происходит в сети интернет-провайдера). И даже то, что по sms маршрутизатор UP — не нормально.

Первая часть

Заходим мы с напарником на маршрутизатор — вроде доступен. Смотрим по логам: OSPF, LDP-соседство не рвал, это уже хорошо.
Предполагаем, что RP=Route Processor ушёл в 100% — так и есть.
show processes cpu sorted показывает, что-то вроде 95%/85% — т.к. цифры совпадают, то RP загружен не процессами, а прерываниями — т.е. много трафика обрабатывается CPU.

Делаем debug netdr — там очень много пакетов, помеченных VLAN 1044. Причём это multicast-пакеты, как те, которые идут в Global к маршрутизатору, так и те, которые в VRF идут от него к клиентам.

В логах мы видим кучу ошибок: Traceback, бла-бла-бла, ошибка памяти и т.п. Сразу некогда было подробно нагуглить, что это за ошибки.

VLAN 1044 на коммутаторе не ищется, только show vlan id 1044 internal usage показывает, что он выдан в интерфейс Po1, а вообще-то Po1 это L3-интерфейс! Почему так оказалось с VLAN 1044 я не знаю, разбираться не стали.

В общем, мы подумали, что проблема связана с передачей multicast. Стали пробовать гасить интерфейс Po1, через который заходит телевидение — но весь трафик пошёл через другой интерфейс, загрузка RP осталась 100%.

Про клиентские сервисы я решил, что точно страдает телевидение. При этом с самого маршрутизатора клиенты в VRF для «юриков» и в VRF для «физиков» пинговались — и я решил, что трафик интернета не страдает. При этом я видел сильную просадку трафика по графикам, но не до нуля. Вероятно, надо было тщательней выяснить момент про клиентские сервисы — пропинговать клиентов из мира, прикинуть, сколько трафика ушло, и сколько из него было телевидения.

Тут наша фантазия иссякла, уже 1 час прошёл, а мы аварию не устранили — эскалировали в отдел развития сети и уведомили начальника. Завели заявку самого высокого приоритета, описали симптомы, свои действия. Я написал в техподдержку, чтобы они учитывали эту аварию при звонках клиентов и сообщали голосом, если будут массовые жалобы клиентов, включенных с этого маршрутизатора.

На этом первая часть заканчивается.

Вторая часть

Итак, мы сдали проблему в отдел развития сети. Но мы оба с напарником не выключились из работы по заявке.

Всё осложнялось тем, что вечер, 21:00-22:00, ЧНН.
Пришлось отвлекаться на балансировку нагрузки во внешних каналах и заведение заявок по упавшим/поднявшимся коммутаторам, неработающим телеканалам и пр. Балансировку я сделал за 5 минут по опыту, и повезло, что крупных аварий не было, а мелкие я обработал или оставил на потом.

Напарник делал диагностику командами show на Cisco 6500, а я гуглил ошибки из сообщений в логах.
Добавлю, что с самого начала аварии Cisco 6500 тупила в консоли и иногда разрывала соединение.
Тут пришёл сигнал из техподдержки, что они не могут зайти на коммутаторы, которые включены от этого маршрутизатора, и что клиенты массово жалуются на торможение сайтов и пингуются с огромными потерями — тут стало понятно, что страдают все сервисы.

Я уже подумал по опыту, что отдел развития сети будет дебажить, а потом всё равно всё закончится перезагрузкой.:) Так что позвонил начальнику монтажников, чтобы он брал консоль с GSM-модемом и ехал на узел связи. Там он должен подключить консоль к Cisco 6500, мы через GSM зайдём на эту консоль и после этого перезагрузим Cisco 6500. Это нужно на тот случай, если после перезагрузки коммутатор не взлетит, и придётся его оживлять.
У начальника монтажников бойцов было мало, некоторым из них предстояли ночные работы, так что он поехал сам.

Ещё я всю информацию своевременно отражал в заявке, не ждал, что отпишусь после устранения аварии. И это правильно — все должны видеть, на какой стадии находится устранение аварии сейчас.

В общем, я нагуглил на cisco.com по сообщению об ошибке какой-то баг Cisco 7600, где сообщалось, что это «глюк», в результате которого коммутатор перестаёт добавлять в CEF новые маршруты. «Глюк» может возникнуть на ровном месте, т.е. не обязательно вызван какими-то обстоятельствами. Помочь должна перезагрузка маршрутизатора (ха-ха!).
Версия IOS у нас была не в точности та же, что в описании бага, но по цифрам такая же, только буквами отличалась.

Вот то сообщение в логах:
%MLSCEF-SP-2-FREEZE: hardware switching disabled on card
http://www.cisco.com/en/US/docs/ios/12_2sr/release/notes/122SRcavs5.html говорит, что это баг CSCsg40573.

И я заметил по графикам, что просело до нуля количество пакетов, обрабатываемых PFC. Я из этого сделал вывод, что страдают все сервисы. Я был взволнован крупной аварией и не очень хорошо владел темой, поэтому я не подумал спокойно: «А что же обрабатывает PFC?» — А PFC как раз продвигает пакеты CEF’ом.
На том маршрутизаторе нет DFC, поэтому всю коммутацию делает PFC.
Ещё меня смутило, что в в выводе команды show ip cef — маршруты были.
Мой напарник по результатам своей диагностики пришёл к выводу, что проблема с CEF.

В это время мне позвонил начальник и сказал, что они с отделом развития сети пришли к выводу, что CEF просто не коммутирует пакеты, и надо перезагружать маршрутизатор.

Они увидели это по команде
#show mls cef hardware

CEF TCAM v2: (FROZEN)
Size: 262144 entries
65536 rows/device, 4 device(s)
32 entries/mask-block
8192 total blocks (32b wide)
1212416 s/w table memory
Options:
sanity check: off
sanity interval: 301 seconds
consistency check: off
consistency interval: 31 seconds
redistribution: off
redistribution interval: 120 seconds
redistribution threshold: 10
compression: off
compression interval: 31 seconds
tcam/ssram shadowing: on
Operation Statistics:
Entries inserted: 0000000026486227
Entries deleted: 0000000026473952
Entries compressed: 0000000002044646
Blocks inserted: 0000000000476132
Blocks deleted: 0000000000475614
Blocks compressed: 0000000000311462
Blocks shuffled: 0000000000007388
Blocks deleted for exception: 0000000000000000
Direct h/w modifications(TCAM): 0000000000000000
Direct h/w modifications(SSRAM):0000000000000000

Double Allocation Attempts :0
Double Freeing Attempts :0
Freeing Others’ Entries Attempts :0
Writing Others’ Entries Attempts :0
Writing To Un-Allocated Entries :0
Suspicious Application Calls :0

Надо обратить внимание на статус CEF — FROZEN и на то, что присутствует Fatal Error.

Мы не стали ждать приезда начальника монтажников, хотя он уже был на подходе, сохранили конфиг, перезагрузили маршрутизатор.
Через 10 минут он загрузился и дальше работал нормально.
Мы проверили, что все сервисы клиентов восстановились.

Прошло уже 2-3 дня, а в логах нет сообщений об ошибках.
Т.е. это был разовый программный сбой.

Для меня выводы

1. Нужно лучше учить матчасть: как работает CEF, какими командами смотреть его состояние. Тогда я бы раньше сделал вывод по графикам, что пропали пакеты с PFC, значит, маршрутизатор пакеты вообще не коммутирует!
На будущее мы сделали threshold на графике — когда количество пакетов на PFC упадёт ниже 5000 в течение 3 минут, придёт sms и e-mail.
2. Эскалацию до отдела развития сети можно было сделать раньше, а не через 1 час — всё-таки у многих клиентов страдали сервисы. На будущее, сделаю так: если я убедился, что массово страдает хотя бы один сервис, например, телевидение, и мы сами не можем починить через 30 минут — эскалируем в отдел развития сети и начальнику. Тут главное — чинить, как можно скорее.