[MAXmks]

Коллеги, добрый день.

 

Имеем следующую ситуацию.

 

ASR1004 ESP20 RP1, железка давно в продакшене. При обновлении IOS на версии 3.10.4, 3.13.1 перестают авторизовываться абоненты, либо сессия очень долго устанавливается однако не полностью отрабатывает IPCP, не передает DNS серверы, терминируются как PPPoE, так и L2TP, на обоих протоколах поведение идентичное.

 

На версиях 3.9.1 и 3.12.1 такой проблемы нет. Однако нам необходимо обновится, т.к. на указанных версиях имеем небольшой, но непонятный баг с авторизацией с windows хостов, авторизуются не с первого раза.

 

Прошу помочь с поиском и исправлением причины такого поведения. Что изменилось с этих версий софта?

 

version 15.4
service timestamps debug datetime msec
service timestamps log datetime msec
service password-encryption
no service dhcp
no platform punt-keepalive disable-kernel-core
!
hostname asr1004
!
boot-start-marker
boot system bootflash:/asr1000rp1-adventerprisek9.03.13.01.S.154-3.S1-ext.bin
boot-end-marker
!
aqm-register-fnf
!
vrf definition Mgmt-intf
!
address-family ipv4
exit-address-family
!
address-family ipv6
exit-address-family
!
logging buffered 409600
enable secret 4 хххх
!
aaa new-model
!
!
aaa group server radius hydra
server хххх auth-port 1812 acct-port 1813
server хххх auth-port 1812 acct-port 1813
ip vrf forwarding Mgmt-intf
!
aaa authentication login default local
aaa authentication ppp STREAM group hydra
aaa authorization exec default local 
aaa authorization network default group hydra 
aaa authorization network STREAM group hydra local 
aaa authorization subscriber-service default local group hydra 
aaa accounting delay-start all
aaa accounting update periodic 15
aaa accounting network STREAM start-stop group hydra
!
!
!
!
aaa server radius dynamic-author
client хххх vrf Mgmt-intf
client хххх vrf Mgmt-intf
server-key 7 хххх
port 3799
auth-type any
!
aaa session-id unique
aaa max-sessions 64000
!
!
subscriber service password 7 005144523C5D1C525D701F163D03
subscriber service multiple-accept
subscriber service session-accounting
subscriber templating
subscriber authorization enable
!
multilink bundle-name authenticated
vpdn enable
vpdn l2tp nas-port-type map all virtual
vpdn history failure table-size 50
!
vpdn-group 1
! Default L2TP VPDN group
! Default PPTP VPDN group
accept-dialin
 protocol any
 virtual-template 1
session-limit 10000
no l2tp tunnel authentication
ip pmtu
ip mtu adjust
!
!
redirect server-group personal-area
server ip 92.62.144.138 port 8001 
!
policy-map type service REDIRECT
10 class type traffic REDIRECT
 redirect to group personal-area
 police input 2048000 512000 1024000
!
!
bba-group pppoe global-pppoe
virtual-template 2
sessions per-vc limit 10000
sessions per-mac limit 1
sessions per-vlan limit 10000 inner 10000
!
!
interface Virtual-Template1
mtu 1460
ip unnumbered TenGigabitEthernet0/0/0.900
no ip unreachables
no ip proxy-arp
ip access-group vt-acl-test in
no logging event link-status
peer default ip address pool pool-1 pool-2 pool-3 pool-4 pool-5 pool-6 pool-7
keepalive 20
ppp authentication chap callin STREAM
ppp authorization STREAM
ppp accounting STREAM
ppp ipcp dns 92.62.144.130 92.62.145.130
ppp ipcp address required
ppp ipcp address unique
!
interface Virtual-Template2
ip unnumbered Loopback0
no ip redirects
no ip proxy-arp
ip mtu 1492
peer default ip address pool pool-1 pool-2 pool-3 pool-4 pool-5 pool-6 pool-7
keepalive 20
ppp authentication chap STREAM
ppp authorization STREAM
ppp accounting STREAM
ppp ipcp dns 92.62.144.130 92.62.145.130
ppp ipcp address required
ppp ipcp address unique
!
!

 

 

 

Дебаг пр попытке установить сессию

 

Aug 31 07:18:07.260: ppp6163 Debug: Condition 2, username madmax triggered, count 1
Aug 31 07:18:07.261: SSS PM [1325097C 13235F80 1323F7F8] [uid:6163][4FAB7844][AAA ID:59025]: AAA author needed for registered user
Aug 31 07:18:07.262: RADIUS/ENCODE(0000E691):Orig. component type = PPPoE
Aug 31 07:18:07.262: RADIUS: DSL line rate attributes successfully added
Aug 31 07:18:07.262: RADIUS(0000E691): Config NAS IP: 172.17.75.25
Aug 31 07:18:07.262: RADIUS(0000E691): Config NAS IPv6: ::
Aug 31 07:18:07.262: RADIUS/ENCODE: No idb found! Framed IP Addr might not be included
Aug 31 07:18:07.262: RADIUS/ENCODE(0000E691): acct_session_id: 1180284
Aug 31 07:18:07.262: RADIUS/ENCODE(0000E691): Acct-session-id pre-pended with Nas Port = 0/0/0/1103.80
Aug 31 07:18:07.262: RADIUS(0000E691): Config NAS IP: 172.17.75.25
Aug 31 07:18:07.262: RADIUS(0000E691): sending
Aug 31 07:18:07.263: RADIUS(0000E691): Send Access-Request to 172.17.75.30:1812 id 1645/204, len 197
Aug 31 07:18:07.263: RADIUS:  authenticator 8E A2 53 2A 35 42 0B 99 - AA F0 A0 45 73 55 BB A0
Aug 31 07:18:07.263: RADIUS:  Framed-Protocol     [7]   6   PPP                       [1]
Aug 31 07:18:07.263: RADIUS:  User-Name           [1]   8   "madmax"
Aug 31 07:18:07.263: RADIUS:  CHAP-Password       [3]   19  *
Aug 31 07:18:07.263: RADIUS:  Calling-Station-Id  [31]  16  "5a64.3a29.e8dc"
Aug 31 07:18:07.263: RADIUS:  NAS-Port-Type       [61]  6   Ethernet                  [15]
Aug 31 07:18:07.263: RADIUS:  NAS-Port            [5]   6   4517968
Aug 31 07:18:07.263: RADIUS:  NAS-Port-Id         [87]  15  "0/0/0/1103.80"
Aug 31 07:18:07.263: RADIUS:  Vendor, Cisco       [26]  41
Aug 31 07:18:07.263: RADIUS:   Cisco AVpair       [1]   35  "client-mac-address=5a64.3a29.e8dc"
Aug 31 07:18:07.263: RADIUS:  Service-Type        [6]   6   Framed                    [2]
Aug 31 07:18:07.263: RADIUS:  NAS-IP-Address      [4]   6   172.17.75.25
Aug 31 07:18:07.263: RADIUS:  Acct-Session-Id     [44]  24  "0/0/0/1103.80_0012027C"
Aug 31 07:18:07.263: RADIUS:  Nas-Identifier      [32]  18  "asr1004.ats99.ru"
Aug 31 07:18:07.263: RADIUS:  Event-Timestamp     [55]  6   1441005487
Aug 31 07:18:07.263: RADIUS(0000E691): Sending a IPv4 Radius Packet
Aug 31 07:18:07.263: RADIUS(0000E691): Started 10 sec timeout
Aug 31 07:18:07.445: RADIUS: Received from id 1645/204 172.17.75.30:1812, Access-Accept, len 119
Aug 31 07:18:07.445: RADIUS:  authenticator C4 44 02 FD 49 1F BE 84 - 64 3C 9D 37 07 94 10 C3
Aug 31 07:18:07.445: RADIUS:  Vendor, Cisco       [26]  32
Aug 31 07:18:07.445: RADIUS:   Cisco AVpair       [1]   26  "ip:sub-policy-In=100M-in"
Aug 31 07:18:07.445: RADIUS:  Vendor, Cisco       [26]  34
Aug 31 07:18:07.445: RADIUS:   Cisco AVpair       [1]   28  "ip:sub-policy-Out=100M-Out"
Aug 31 07:18:07.445: RADIUS:  Vendor, Cisco       [26]  27
Aug 31 07:18:07.445: RADIUS:   Cisco AVpair       [1]   21  "ip:inacl=session-in"
Aug 31 07:18:07.445: RADIUS:  Session-Timeout     [27]  6   2419200
Aug 31 07:18:07.445: RADIUS(0000E691): Received from id 1645/204
Aug 31 07:18:07.447: SSS AAA AUTHOR[13253638 1323EBFC 1323E458] [uid:6163][AAA ID:59025]: Root SIP PPPoE
Aug 31 07:18:07.448: SSS AAA AUTHOR[13253638 1323EBFC 1323E458] [uid:6163][AAA ID:59025]:  Enable PPPoE parsing
Aug 31 07:18:07.448: SSS AAA AUTHOR[13253638 1323EBFC 1323E458] [uid:6163][AAA ID:59025]:  Enable PPP parsing
Aug 31 07:18:07.449: SSS AAA AUTHOR[1324D90C 13253A44 1323EBFC] [uid:6163][AAA ID:59025]: Active key set to Unauth-User
Aug 31 07:18:07.450: SSS AAA AUTHOR[1324D90C 13253A44 1323EBFC] [uid:6163][AAA ID:59025]: Authorizing key madmax
Aug 31 07:18:07.450: SSS AAA AUTHOR[1324DAEC 1324D90C 13253A44] [uid:6163][AAA ID:59025]: Spoofed AAA reply sent for key madmax
Aug 31 07:18:07.451: SSS AAA AUTHOR[1324B278 13232130 1321FC44] [uid:6163][AAA ID:59025]: Received an AAA pass
Aug 31 07:18:07.451: SSS PM [132519A8 13254CC4 1324B278] [uid:6163][4FAB7844][AAA ID:59025]:
policy key list doesn't have IPv4 address
Aug 31 07:18:07.452: SSS AAA AUTHOR[13252600 13254CC4 1324B278] [uid:6163][AAA ID:59025]: SIP PPP[12B4E068] parsed as Success
Aug 31 07:18:07.453: SSS AAA AUTHOR[13252600 13254CC4 1324B278] [uid:6163][AAA ID:59025]: SIP PPP[1366BCE8] parsed as Ignore
Aug 31 07:18:07.454: SSS AAA AUTHOR[13252600 13254CC4 1324B278] [uid:6163][AAA ID:59025]: SIP PPPoE[12BE91F8] parsed as Success
Aug 31 07:18:07.454: SSS AAA AUTHOR[1324D90C 13254B6C 1324B278] [uid:6163][AAA ID:59025]: No service authorization info found
Aug 31 07:18:07.455: SSS AAA AUTHOR[1324D90C 13254B6C 1324B278] [uid:6163][AAA ID:59025]: Active Handle present - 49000D95
Aug 31 07:18:07.455: SSS AAA AUTHOR[1324D90C 13254B6C 1324B278] [uid:6163][AAA ID:59025]: Freeing Active Handle; SSS Policy Context Handle = 47010B7E
Aug 31 07:18:07.456: SSS AAA AUTHOR[1324D90C 1324F6FC 1324D90C] [uid:6163][AAA ID:59025]: Cancel request

Aug 31 07:48:57.239: Vi2.3176 IPCP AUTHOR: no author-info for primary dns
Aug 31 07:48:57.240: Vi2.3176 IPCP AUTHOR: no author-info for seconday dns
Aug 31 07:48:57.241: Vi2.3176 IPCP AUTHOR: no author-info for primary dns
Aug 31 07:48:57.241: Vi2.3176 IPCP AUTHOR: no author-info for seconday dns
Aug 31 07:52:36.074: ppp5256 PPP: Receive Attrs from[sSS] Keep[NCPs] MERGE
Aug 31 07:52:36.074: ppp5256 PPP: Skip Attr: sub-policy-In        0   "100M-in"
Aug 31 07:52:36.074: ppp5256 PPP: Skip Attr: sub-policy-Out       0   "100M-Out"
Aug 31 07:52:36.074: ppp5256 PPP: Skip Attr: inacl                0   "session-in"
Aug 31 07:52:36.074: ppp5256 PPP: Skip Attr: timeout              0   2419200 (0x24EA00)
Aug 31 07:52:36.131: Vi2.3074 Debug: Condition 2, username madmax triggered, count 1
Aug 31 07:52:36.131: Vi2.3074 LCP AUTHOR: Process LCP Author Data
Aug 31 07:52:36.131: Vi2.3074 LCP AUTHOR: Process Attr: timeout
Aug 31 07:52:36.131: Vi2.3074 LCP AUTHOR: Authorization succeeded
Aug 31 07:52:36.132: Vi2.3074 PPP IPCP: negotiation authorized = 1, tacacs author = 0
Aug 31 07:52:36.132: Vi2.3074 PPP IPCP: neg is authorized, processing CP UP event

На этом месте установка сессии останавливается (у абона висит "регистрация компьютера в сети")

 

лог фрирадиуса

31.08.2015 11:13:16.194 DEBUG    Result status: 200, body: {"RAD_REPLY": {"Primary-dns": "92.62.144.130", "Cisco-AVPair": ["ip:sub-policy-In=100M-in", "ip:sub-policy-Out=100M-Out", "ip:inacl=session-in"], "Session-Timeout": "2419200"}, "result": 2, "RAD_CHECK": {"User-Name": "madmax", "Hydra-Equip-Cache-ID": "55e2e7116cb9ba370b7282b0", "Auth-Type": "CHAP", "Cleartext-Password": "madmax", "Hydra-Netserv-Cache-ID": "55e3b93b6cb9ba370b729819"}}

 

Как я говорю, подключение в итоге может установится, но абонент не получит по IPCP адреса DNS.

Изменено 31 августа, 2015 пользователем MAXmks

[MAXmks]

Дополню, кое что локализовали. Если в виндовс pppoe клиенте отключить использование LCP, то все становится гораздо лучше, сессии устанавливаются быстро.

 

Господа, что это может быть?

[MAXmks]

Выяснили кое что еще.

 

Aug 31 10:33:05.556: Vi2.2764 IPCP: I CONFREQ [REQsent] id 7 len 34
Aug 31 10:33:05.556: Vi2.2764 IPCP:    Address 0.0.0.0 (0x030600000000)
Aug 31 10:33:05.556: Vi2.2764 IPCP:    PrimaryDNS 0.0.0.0 (0x810600000000)
Aug 31 10:33:05.556: Vi2.2764 IPCP:    PrimaryWINS 0.0.0.0 (0x820600000000)
Aug 31 10:33:05.556: Vi2.2764 IPCP:    SecondaryDNS 0.0.0.0 (0x830600000000)
Aug 31 10:33:05.556: Vi2.2764 IPCP:    SecondaryWINS 0.0.0.0 (0x840600000000)
Aug 31 10:33:05.556: Vi2.2764 IPCP AUTHOR: Start.  Her address 0.0.0.0, we want 0.0.0.0
Aug 31 10:33:05.556: Vi2.2764 IPCP AUTHOR: Done.  Her address 0.0.0.0, we want 0.0.0.0
Aug 31 10:33:05.556: Vi2.2764 IPCP: Pool returned 92.62.156.108
Aug 31 10:33:05.556: Vi2.2764 IPCP: O CONFREJ [REQsent] id 7 len 16
Aug 31 10:33:05.556: Vi2.2764 IPCP:    PrimaryWINS 0.0.0.0 (0x820600000000)
Aug 31 10:33:05.556: Vi2.2764 IPCP:    SecondaryWINS 0.0.0.0 (0x840600000000)
Aug 31 10:33:05.556: Vi2.2764 IPCP: Event[Receive ConfReq-] State[REQsent to REQsent]
Aug 31 10:33:05.556: Vi2.2764 PPP: Control packet rate limit 10 reached
Aug 31 10:33:05.556: Vi2.2764 PPP: Entering block state for 30 seconds
Aug 31 10:33:05.556: Vi2.2764 PPP: Packet throttled, Dropping packet
Aug 31 10:33:05.566: Vi2.2764 PPP: Packet throttled, Dropping packet
Aug 31 10:33:07.433: Vi2.2764 PPP: Packet throttled, Dropping packet
Aug 31 10:33:10.434: Vi2.2764 PPP: Packet throttled, Dropping packet
Aug 31 10:33:14.433: Vi2.2764 PPP: Packet throttled, Dropping packet
Aug 31 10:33:18.433: Vi2.2764 PPP: Packet throttled, Dropping packet
Aug 31 10:33:22.439: Vi2.2764 PPP: Packet throttled, Dropping packet

 

 

Сделали

ppp packet throttle 30 1 30 

 

Получил в логах

Aug 31 10:47:06.301: Vi2.3855 PPP DISC: Peer address not unique

 

Однако в списке ppp сессий такого адреса не нашол, не знаю почему ASR решила, что он не unique!

 

Убрал с Virtual-template команду ppp ipcp address unique

no ppp ipcp address unique

 

Теперь все работает как часы, но непонятно какие проблемы могут быть изза no ppp ipcp address unique на Virtual-template?

 

Что думаете?

[ShyLion]

Теперь все работает как часы, но непонятно какие проблемы могут быть изза no ppp ipcp address unique на Virtual-template?

Что думаете?

 

А пулы не пересекаются? (если их можно такие вообще прописать...)

[ShyLion]

Вожможно ***нент подсовывает свой, ранее использовавшися адрес.

Попробуй на тимплейте:

 

peer ip address forced

[MAXmks]

Теперь все работает как часы, но непонятно какие проблемы могут быть изза no ppp ipcp address unique на Virtual-template?

Что думаете?

 

А пулы не пересекаются? (если их можно такие вообще прописать...)

 

Нет пулы не пересекаются.

[MAXmks]

Вожможно ***нент подсовывает свой, ранее использовавшися адрес.

Попробуй на тимплейте:

 

peer ip address forced

 

Сомневаюсь, тестили своими ноутами с Win7 и Linux, и там и там одинаковая трабла. Больше пока не чего не буду менять, сейчас все работает, а железяка в продакшене там около 6000 сессий. Меня больше волнует друге моменты:

 

1. На сколько плохо, что на темплейте нет ppp ipcp address unique, чем это может быть чревато? Дело в том, что после того как все наладилось мы попытались поднять сессию, прописывая в клиенте уже используемый адрес, сессию поднять не смогли, циска отбила. Так может и не столь критична эта проверка на уникальность?

 

2. Что изменилось в ios релизах 3.10.4 и 3.13.1, по сравнению 3.9.1 и 3.12.1, что в старых иосах были редкие заявки на неустановку сессий с первого раза, а в новых тот же конфиг просто встал раком.

[ShyLion]

Вожможно ***нент подсовывает свой, ранее использовавшися адрес.

Попробуй на тимплейте:

 

peer ip address forced

 

Сомневаюсь, тестили своими ноутами с Win7 и Linux, и там и там одинаковая трабла. Больше пока не чего не буду менять, сейчас все работает, а железяка в продакшене там около 6000 сессий. Меня больше волнует друге моменты:

 

1. На сколько плохо, что на темплейте нет ppp ipcp address unique, чем это может быть чревато? Дело в том, что после того как все наладилось мы попытались поднять сессию, прописывая в клиенте уже используемый адрес, сессию поднять не смогли, циска отбила. Так может и не столь критична эта проверка на уникальность?

 

2. Что изменилось в ios релизах 3.10.4 и 3.13.1, по сравнению 3.9.1 и 3.12.1, что в старых иосах были редкие заявки на неустановку сессий с первого раза, а в новых тот же конфиг просто встал раком.

 

Тут наверное только TAC ответит.

[mikezzzz]

Вожможно ***нент подсовывает свой, ранее использовавшися адрес.

Попробуй на тимплейте:

 

peer ip address forced

 

Сомневаюсь, тестили своими ноутами с Win7 и Linux, и там и там одинаковая трабла. Больше пока не чего не буду менять, сейчас все работает, а железяка в продакшене там около 6000 сессий. Меня больше волнует друге моменты:

 

1. На сколько плохо, что на темплейте нет ppp ipcp address unique, чем это может быть чревато? Дело в том, что после того как все наладилось мы попытались поднять сессию, прописывая в клиенте уже используемый адрес, сессию поднять не смогли, циска отбила. Так может и не столь критична эта проверка на уникальность?

 

2. Что изменилось в ios релизах 3.10.4 и 3.13.1, по сравнению 3.9.1 и 3.12.1, что в старых иосах были редкие заявки на неустановку сессий с первого раза, а в новых тот же конфиг просто встал раком.

 

добрый день, я бы глянул что происходит в дампе Вашего радиуса, то есть именно содержимое пакета Reply.

фича ppp ipcp address unique проверяет, что в ответе радиуса не содержится уже занятый каким-либо клиентом IP адрес. У вас адреса выдаются самой циской через IPCP, как я понял. Возможно радиус стряпает какой-то ответ вида - subscriber-ip="0.0.0.0" просто потому что может:)

 

p.s. насчет ppp ipcp address unique и радиуса, я возможно погорячился, но глянуть дебаг радиуса не помешало бы

Изменено 1 сентября, 2015 пользователем mikezzzz

[Alex780]

Такое начинается с 12 версии

[Pro-R]

Прочитал и прослезился, не только у нас такая проблема.

Лирика:

Где-то год назад при очередном баге на ASR1013 с 16000 сессий, Cisco TAC рекомендовала нам обновить IOS, перейти с 12 версии на 15.

При обновлении IOS запускался, туннели устанавливались, но пользователи не подключались, железка уходила в себя. В момент перезагрузки около 6000 пользователей не могли авторизоваться, хотя на 12 версии всё работало и хватало 5-10 минут чтобы прожевать всех и нагрузка по CPU падала до обычного уровня.

Так вот я про выше написанное сообщение

Тут наверное только TAC ответит.

- НИХРЕНА ОН НЕ ПОМОЖЕТ не всегда он поможет.

Собирали статистику, отправляли отчеты, потом давали удаленный доступ специалистам по поддержке - тоже ноль, собирали конференции со специалистами Cisco TAC с других континентов, они якобы собирали стенды, !НО! решения проблемы никто не мог найти. Это при том что железка одна на всю сеть и эксперименты с ней ставить на живых хомячках - опасная штука, даже в 5 утра когда клиентов всего ~ 6000.

Про нашу проблему забывали, специалисты уходили в отпуска, специалисты менялись и т.д.

В итоге мы забили на малозначительный баг на 12 иосе, еще раз оценили его стабильность :) и решили закрыть обращение.

По проблеме:

Недавно поставили резервный ASR1002-x, и решили сразу поставить (03.10.05.S.153-3.S5-ext), обкатать и допились самим.

Конфиг переехал практически без изменений, всё завелось, только тестовая авторизация проходила по 30-40 сек, что настораживало.

Наткнулся на данную статью, прописал:

ppp packet throttle 30 1 30 

и о чудо! Спасибо MAXmks!

P.S.: Пришли к выводу что на ASR1013 и 15 IOS могла быть такая же проблема, только сразу 6000 пользователей убивали его и он зависал.

[mikezzzz]

тема! спасибо ppp packet throttle 30 1 30 за наше счастливое детство ) на 10.6 тоже медленно авторизовывалось, душила циска видать

[coobic]

Pro-R: проблема с тем, что при значительном количестве сессий PPPoE не устанавливается на 15-й ветке и устанавливается на 12-й скорее всего связана с call admission (если дело не в RADIUS).

Мы с подобной проблемой общались как-то с TAC, подобрали параметры:

 

call admission new-model

call admission limit 700

call admission cpu-limit 85

call admission vpdn 30 1

call admission pppoe 20 1

call admission pppoa 30 1

call admission ip 30 1

 

тут часть лишнего, но pppoe есть и при такой конфигурации (если дело в ней) 6000 сессий за 15-20 минут подключаются к ASR1002.

 

MAXmks, спасибо за рецепт - мы сейчас общаемся с TAC на эту тему и пытаемся получить рекомендации (а также список существенных изменений в последних IOS касательно PPP/PPPoE), в сети есть топики:

https://supportforums.cisco.com/discussion/12568991/pppoe-ppp-packet-throttle#comment-10678686

https://supportforums.cisco.com/discussion/12397371/ppp-pppoe-connection-failing

В этих топиках есть ссылки на внутренние кейсы, которые (даже при наличии регистрации и контракта) не доступны.