forum.bitel.ru
http://forum.bitel.ru/

Непонятный разрыв сессии, атрибуты cisco
http://forum.bitel.ru/viewtopic.php?f=5&t=1838		 Страница 1 из 1
Автор:  jack7 [ 22 янв 2009, 18:26 ]
Заголовок сообщения:  Непонятный разрыв сессии, атрибуты cisco
Пользователи PPPoE жалуются на частые переподключения сессий, каждые 2-3 минуты, бывает реже, но часто
в логах radius.log видны следующие записи

Цитата:
INFO 22.01.2009 16:41:02 ACCOUNT:
Type=ACCOUNTING_REQUEST
Attributes:
User-Name=47
NAS-IP-Address=192.168.6.1
NAS-Port=44052
Service-Type=2
Framed-Protocol=1
<AttrCode[197]>=undef
Framed-IP-Address=10.22.1.32
<AttrCode[196]>=undef
<AttrCode[198]>=undef
<AttrCode[193]>=undef
<AttrCode[192]>=undef
<AttrCode[195]>=undef
NAS-Port-Id=0/0/0/0
<AttrCode[151]>=undef
NAS-Identifier=red_queen
Acct-Input-Octets=2108
Acct-Output-Octets=3952
Acct-Status-Type=2
Acct-Delay-Time=0
Acct-Session-Time=150
Acct-Input-Packets=43
Acct-Session-Id=0000AC14
Acct-Authentic=1
<AttrCode[255]>=undef
Acct-Terminate-Cause=8
Acct-Output-Packets=36
Event-Timestamp=1232624692
<AttrCode[190]>=undef
<AttrCode[191]>=undef
NAS-Port-Type=5
cisco-avpair=ppp-disconnect-cause=Missed too many keepalives
cisco-avpair=connect-progress=LAN Ses Up
cisco-avpair=nas-tx-speed=1000000000
cisco-avpair=nas-rx-speed=1000000000
cisco-avpair=disc-cause-ext=TCP Foreign Host Close
cisco-avpair=client-mac-address=0029.c6ce.21cf



причина "Missed too many keepalives" не понятна, что это может значить?
Автор:  Victor [ 26 янв 2009, 10:14 ]
Заголовок сообщения: 
Это значит, что NAS не получил ответа на несколько посланых им PPPoE-keepalive пакетов и разорвал сессию. Могу предположить, что на канале между NAS и клиентом очень много потерь.
Автор:  jack7 [ 26 янв 2009, 11:21 ]
Заголовок сообщения: 
ок, спасибо за ответ
Автор:  jack7 [ 15 апр 2009, 12:50 ]
Заголовок сообщения: 
Код:
Acct-Terminate-Cause=6

известно, что это Admin Reset (по RFC)

из-за чего может отправлятся такой разрыв соединения?
очень интересно, так как есть пользователи с постоянными обрывами связи именно с таким атрибутом
Автор:  Victor [ 15 апр 2009, 13:21 ]
Заголовок сообщения: 
jack7 писал(а):
Код:
Acct-Terminate-Cause=6

известно, что это Admin Reset (по RFC)

из-за чего может отправлятся такой разрыв соединения?
очень интересно, так как есть пользователи с постоянными обрывами связи именно с таким атрибутом

Это принудительное отключение абонента НАСом по команде с консоли, snmp, pod(?).
Автор:  jack7 [ 15 апр 2009, 13:22 ]
Заголовок сообщения: 
у нас в качестве pppoe-сервера cisco, и оттуда команд на сброс сессий не было
Автор:  Victor [ 15 апр 2009, 13:24 ]
Заголовок сообщения: 
jack7 писал(а):
у нас в качестве pppoe-сервера cisco, и оттуда команд на сброс сессий не было

А как у вас сессии разрываются? SNMP? Посмотрите логи радиус-сервера, посылал ли он команды на отключение...
Автор:  jack7 [ 15 апр 2009, 13:27 ]
Заголовок сообщения: 
вот лог радиуса

Цитата:
15 10:37:34
Type=AUTHENTICATION_REQUEST
Attributes:
User-Name=1811
NAS-Identifier=red_queen
NAS-Port-Id=0/0/0/0
CHAP-Password=\u1\u177N4yJ\u160\u63\u632\u63\u63\u63\u91!\u63\u63
NAS-IP-Address=192.168.6.1
NAS-Port=1302760
Service-Type=2
Framed-Protocol=1
Acct-Session-Id=0013E0E8
NAS-Port-Type=5
cisco-avpair=client-mac-address\u61001e.e591.1013

15 10:37:34
Type=AUTHENTICATION_ACCEPT
Process time:21
Attributes:
Acct-Interim-Interval=60
Service-Type=2
Framed-Protocol=1
Framed-IP-Address=10.2.2.252
cisco-avpair=ip:sub-qos-policy-out\u61FLAT
cisco-avpair=ip:inacl\u61balance-out

15 10:37:34
Type=ACCOUNTING_REQUEST
Attributes:
User-Name=1811
NAS-Identifier=red_queen
NAS-IP-Address=192.168.6.1
NAS-Port=1302760
Service-Type=2
Framed-Protocol=1
<AttrCode[196]>=undef
Acct-Status-Type=1
Acct-Delay-Time=0
Acct-Session-Id=0013E0E8
Acct-Authentic=1
NAS-Port-Id=0/0/0/0
NAS-Port-Type=5
<AttrCode[151]>=undef
cisco-avpair=connect-progress\u61Call Up
cisco-avpair=client-mac-address\u61001e.e591.1013
<VendorCode[9]><AttrCode[38]>=undef

15 11:47:02
Type=ACCOUNTING_REQUEST
Attributes:
User-Name=1811
NAS-IP-Address=192.168.6.1
NAS-Port=1302760
Service-Type=2
Framed-Protocol=1
<AttrCode[197]>=undef
Framed-IP-Address=10.2.2.252
<AttrCode[196]>=undef
<AttrCode[198]>=undef
<AttrCode[193]>=undef
<AttrCode[192]>=undef
<AttrCode[195]>=undef
NAS-Port-Id=0/0/0/0
<AttrCode[151]>=undef
NAS-Identifier=red_queen
Acct-Input-Octets=57198
Acct-Output-Octets=157909
Acct-Status-Type=2
Acct-Delay-Time=0
Acct-Session-Time=4167
Acct-Input-Packets=501
Acct-Session-Id=0013E0E8
Acct-Authentic=1
<AttrCode[255]>=undef
Acct-Terminate-Cause=6
Acct-Output-Packets=990
<AttrCode[190]>=undef
<AttrCode[191]>=undef
NAS-Port-Type=5
cisco-avpair=ppp-disconnect-cause\u61Lower Layer disconnected
cisco-avpair=connect-progress\u61LAN Ses Up
cisco-avpair=nas-tx-speed\u611000000000
cisco-avpair=nas-rx-speed\u611000000000
cisco-avpair=disc-cause-ext\u61Local Admin Disc
cisco-avpair=client-mac-address\u61001e.e591.1013
<VendorCode[9]><AttrCode[38]>=undef
Автор:  Victor [ 15 апр 2009, 13:36 ]
Заголовок сообщения: 
connection.log относительно этой сессии?
Автор:  jack7 [ 15 апр 2009, 14:53 ]
Заголовок сообщения: 
лог по времени отличается, но суть та же

Код:
NFO   15.04.2009 14:45:59  [ 21666; 1811; 60109 ] DialUpNASConnection update connection..
INFO   15.04.2009 14:45:59  [ 21666; 1811; 60109 ] DialUpNASConnection set STATUS=1
INFO   15.04.2009 14:46:34  [ 21666; 1811; 60109 ] Set connection to KILL
INFO   15.04.2009 14:46:35  [ 21666; 1811; 60109 ] sendKillRequest
INFO   15.04.2009 14:46:35  [ 21666; 1811; 60109 ] SNMP reset request: set 1.3.6.1.4.1.9.9.150.1.1.3.1.5.1312938 i 1
INFO   15.04.2009 14:46:35  [ 21666; 1811; 60109 ] IP address unregistred from collector
INFO   15.04.2009 14:46:35  [ 21666; 1811; 60109 ] DialUpNASConnection stoppingConnection
INFO   15.04.2009 14:46:35  [ 21666; 1811; 60109 ] DialUpNASConnection has stop Packet => true
INFO   15.04.2009 14:46:35  [ 21666; 1811; 60109 ] DialUpNASConnection set STATUS=3
INFO   15.04.2009 14:46:35  [ 21666; 1811; 60109 ] DialUpNASConnection sessionTime => 2435
Автор:  Victor [ 15 апр 2009, 15:15 ]
Заголовок сообщения: 
Если видимых причин для отключения не видите, а биллинг отключает (а это судя по логам именно биллинг), то кроме разработчиков Вам никто не поможет.
Попробуйте перевести connection.log в DEBUG-рижим, будет больше инфы. Только аккуратней, там сыпется очень много и файлы раздуваются очень быстро.
Автор:  jack7 [ 15 апр 2009, 15:34 ]
Заголовок сообщения: 
а как перевести connection.log в debug?
Автор:  Victor [ 15 апр 2009, 15:39 ]
Заголовок сообщения: 
jack7 писал(а):
а как перевести connection.log в debug?

файл log4j_radius.properties
Строчка:
log4j.logger.connections=INFO, A2
INFO поменяйте на DEBUG и перезапустите радиус-сервер.
На постоянку не держите, ибо кроме раздувающихся логов будет заметное снижение производительности.
Там же можно поменять количество создаваемых файлов и их размер.
Автор:  jack7 [ 15 апр 2009, 15:56 ]
Заголовок сообщения: 
Victor, спасибо

включил, вот результат
Код:
INFO   15.04.2009 15:54:41  [ 70009; 2090; 81811 ] DialUpNASConnection startConnection mode=1
INFO   15.04.2009 15:54:41  [ 70009; 2090; 81811 ] DialUpNASConnection set STATUS=1
INFO   15.04.2009 15:54:41  [ 70009; 2090; 81811 ] IP address register on collector
INFO   15.04.2009 15:54:44  [ 21666; 1811; 84070 ] DialUpNASConnection startConnection mode=1
INFO   15.04.2009 15:54:44  [ 21666; 1811; 84070 ] DialUpNASConnection set STATUS=1
INFO   15.04.2009 15:54:44  [ 21666; 1811; 84070 ] IP address register on collector
INFO   15.04.2009 15:54:44  192.168.6.1 Session restored for login: 1811; contract: 21666; ipaddr: 10.2.2.252
INFO   15.04.2009 15:54:49  [ 21666; 1811; 68769 ] Set status SUSPENDED on UpdateSuspendedSetter, time after last update: 35674
INFO   15.04.2009 15:54:49  [ 21666; 1811; 68769 ] DialUpNASConnection set STATUS=2
INFO   15.04.2009 15:54:49  [ 21666; 1811; 84070 ] Breaking connection by session count limit..
INFO   15.04.2009 15:54:49  [ 21666; 1811; 84070 ] Set connection to KILL
INFO   15.04.2009 15:54:51  [ 21666; 1811; 84070 ] sendKillRequest
INFO   15.04.2009 15:54:51  [ 21666; 1811; 84070 ] SNMP reset request: set 1.3.6.1.4.1.9.9.150.1.1.3.1.5.1315743 i 1
INFO   15.04.2009 15:54:51  [ 21666; 1811; 84070 ] IP address unregistred from collector
INFO   15.04.2009 15:54:51  [ 21666; 1811; 84070 ] DialUpNASConnection stoppingConnection
INFO   15.04.2009 15:54:51  [ 21666; 1811; 84070 ] DialUpNASConnection has stop Packet => true
INFO   15.04.2009 15:54:51  [ 21666; 1811; 84070 ] DialUpNASConnection set STATUS=3
INFO   15.04.2009 15:54:51  [ 21666; 1811; 84070 ] DialUpNASConnection sessionTime => 4061


судя по всему превышено допустимое количество сессий
Страница 1 из 1 Часовой пояс: UTC + 5 часов [ Летнее время ]
Powered by phpBB® Forum Software © phpBB Group
http://www.phpbb.com/