Radius выдает дублирующиеся IPы

Технические вопросы по UTM 5.0
Lelik85
Сообщения: 76
Зарегистрирован: Вт апр 18, 2006 16:14

Radius выдает дублирующиеся IPы

Сообщение Lelik85 »

FreeBSD,MPD4.3,5.2.1-004+netup_radius
После массовой смены тарифных планов появилась следующая проблема:
Netup_radius начал выдавать пользователям одинаковые IP-адреса.
При подключении абонентку выдается ИП из пула и привязывается к нему в биллинге. Трафик считается и тарифицируется этому пользователю. Через некоторое время второй пользователь авторизовывается,получает этот же ИП,отвязывается от первого пользователя в биллинге и привязывается второму. Первый пр этом остается на линии и у него работает интернет. У второго же ниче не работает,но трафик,пользуемый первым пользователем теперь записывается и тарифицируется второму.
ИПы выдаются динамически из пула так,как это описано в документации. Имеются 3 услуги (Коммутируемый доступ,передача трафика,периодическая услуга абонентской платы). Стоят обе галки "динамической распределение ИП-адресов".
Для всех тарифов (кроме безлимитных) используется общий пул *.*.29.128/255.255.255.128. Есть 4 безлимитных тарифа. Для каждого отдельный пул по 16 ИПов из диапазона *.*.29.1-64.
Дублирующиеся ИПы начинают выдаваться примерно через сутки после запуска NASa. Наблюдается это только для основного пула. Для безлимитных такой проблемы нету.
Перезапуск NASa спасает.
Наблюдение: ниразу не видел,чтобы абоненту был выдан ИП больше 29.200. Судя по всему ИПы выдаются до определенного порога и начинают выдаваться снова со 128 ИПа. Хотя одновременно больше 60 человек (вместе с безлимитчиками) никогда не подключалось.
Тарифные планы при смене делал один в один со старыми. Настройки идентичны.
Перерыл уже все что тока можно было. Нету ошибок в настройках.
Есть предположения куда копать?

magicjohnson
Сообщения: 2
Зарегистрирован: Чт янв 17, 2008 08:19

Сообщение magicjohnson »

Заметил такую же проблему, неужели никто не знает как бороться с багой?
RHEL AS4, PPPoE, UTM5.2.1-003+utm5_radius

Lelik85
Сообщения: 76
Зарегистрирован: Вт апр 18, 2006 16:14

Сообщение Lelik85 »

Up

Аватара пользователя
Chris
Сообщения: 2323
Зарегистрирован: Чт июн 02, 2005 14:08
Откуда: 33 76 77 71 86 37 98

Сообщение Chris »

Down.

симптомы какие? есть ли незавершенные сессии? либо преждевременно завершенные?

Lelik85
Сообщения: 76
Зарегистрирован: Вт апр 18, 2006 16:14

Сообщение Lelik85 »

censored
Последний раз редактировалось Lelik85 Сб фев 09, 2008 18:29, всего редактировалось 1 раз.

Lelik85
Сообщения: 76
Зарегистрирован: Вт апр 18, 2006 16:14

Сообщение Lelik85 »

Up.
Что имею:
Есть MPD5 (перебрано 3 версии: 4.1,4.1 и 5)
utm5.2.1-004 + netup_radius

Ситуация описана в первом посте с той лишь разницей что для безлимитных тарифов ситуация имеет место быть.
Для каждого безлимитного тарифа выделен пул из 16 ИПов.
В каждом безлимитном тарифе сейчас по 11 человек.
Судя по используемым ИПам - одновременно больше 7 безлимитчиков на линии небыло.
Для "лимитных" тарифов выделен пул из 128 ИПов. (ИПы 128-256)
ИПа выше 191 ни разу не видел.

Наблюдения:
Смотрю отчет по модемным и ВПН-сессиям в интерфейсе админа. Если не понятно будет - скриншетов накидаю.
Опишу пример для одного ползователя.

Код: Выделить всё

Дата начала: 19:25:30
Дата окончания: 23:59:34
Полученый IP: x.x.x.34
ID сессии NAS: 2387132-VPN42
Логин: test
Принято: 11223344
Далее появляется следующаяя строка

Код: Выделить всё

Дата начала: 23:59:35
Дата окончания: 00:15:56
Полученый IP: 0.0.0.0
ID сессии NAS: 2387132-VPN42
Логин: test
Принято: 211334
А в это время в логах netup_radius:
Вот так выглядит стандартный Accounting-ответ от NAS для этого пользователя (идентичные блоки повторяются с момента подключения пользователя)(выборка производилась по ID сессии 2387132-VPN42)

Код: Выделить всё

?Debug : Feb 07 23:57:26 RadiusSocket: Waiting for RADIUS raw data 
?Debug : Feb 07 23:57:26 RadiusSocket: RADIUS raw data sent 
?Debug : Feb 07 23:57:27 RADIUS Stream[plugin]: Ping reply received 
?Debug &#58; Feb 07 23&#58;57&#58;27 StreamConnection&#58; Message id <0x202f>, handler returns 0 
?Debug &#58; Feb 07 23&#58;57&#58;28 RadiusSocket&#58; RADIUS packet successfully received 
?Debug &#58; Feb 07 23&#58;57&#58;28 RadiusSocket&#58; RADIUS raw data obtained 
?Debug &#58; Feb 07 23&#58;57&#58;28 RADIUS Packet&#58; Size <181>; HDR.Size <181> 
?Debug &#58; Feb 07 23&#58;57&#58;28 AcctServer&#58; Recv... 
?Debug &#58; Feb 07 23&#58;57&#58;28 AcctServer&#58; Packet from <x.x.x.x> packet dump&#58; RPacket&#58; 
Code&#58; 4; ID&#58; 78 
<Vendor&#58; 0; Attr&#58; 1>&#91;4&#93;&#58; 67756c61 
<Vendor&#58; 0; Attr&#58; 4>&#91;4&#93;&#58; ac1de5fe 
<Vendor&#58; 0; Attr&#58; 5>&#91;4&#93;&#58; 00000029 
<Vendor&#58; 0; Attr&#58; 6>&#91;4&#93;&#58; 00000002 
<Vendor&#58; 0; Attr&#58; 7>&#91;4&#93;&#58; 00000001 
<Vendor&#58; 0; Attr&#58; 8>&#91;4&#93;&#58; ac1d1d22 
<Vendor&#58; 0; Attr&#58; 9>&#91;4&#93;&#58; ffffffff 
<Vendor&#58; 0; Attr&#58; 31>&#91;14&#93;&#58; 3137322e32392e3232382e323136 
<Vendor&#58; 0; Attr&#58; 32>&#91;5&#93;&#58; 616c706861 
<Vendor&#58; 0; Attr&#58; 40>&#91;4&#93;&#58; 00000003 
<Vendor&#58; 0; Attr&#58; 42>&#91;4&#93;&#58; 0013fbe1 
<Vendor&#58; 0; Attr&#58; 43>&#91;4&#93;&#58; 003ef929 
<Vendor&#58; 0; Attr&#58; 44>&#91;13&#93;&#58; 323338373133322d76706e3432 
<Vendor&#58; 0; Attr&#58; 45>&#91;4&#93;&#58; 00000001 
<Vendor&#58; 0; Attr&#58; 46>&#91;4&#93;&#58; 00003fc3 
<Vendor&#58; 0; Attr&#58; 47>&#91;4&#93;&#58; 00006c18 
<Vendor&#58; 0; Attr&#58; 48>&#91;4&#93;&#58; 0000818e 
<Vendor&#58; 0; Attr&#58; 50>&#91;13&#93;&#58; 323338373133322d76706e3432 
<Vendor&#58; 0; Attr&#58; 51>&#91;4&#93;&#58; 00000001 
<Vendor&#58; 0; Attr&#58; 52>&#91;4&#93;&#58; 00000000 
<Vendor&#58; 0; Attr&#58; 53>&#91;4&#93;&#58; 00000000 
<Vendor&#58; 0; Attr&#58; 61>&#91;4&#93;&#58; 00000005 
 
?Debug &#58; Feb 07 23&#58;57&#58;28 RADIUS DBA&#58; NAS found. Data size <0> 
?Debug &#58; Feb 07 23&#58;57&#58;28 AcctServer&#58; Acct packet with session ID&#58; 2387132-vpn42 
?Debug &#58; Feb 07 23&#58;57&#58;28 RADIUS DBA&#58; NAS found. Data size <0> 
?Debug &#58; Feb 07 23&#58;57&#58;28 AcctServer&#58; Acct-Interim-Update packet 
?Debug &#58; Feb 07 23&#58;57&#58;28 AcctServer&#58; Acct-Start&#58; User <test>
?Debug &#58; Feb 07 23&#58;57&#58;28 AcctServer&#58; Updating session <2387132-vpn42> input/output octets <1309665>/<4127017> session time <16323> 
?Debug &#58; Feb 07 23&#58;57&#58;28 RADIUS DBA&#58; Interim updating session <2387132-vpn42> with timestamp <1202403448> 
?Debug &#58; Feb 07 23&#58;57&#58;28 RADIUS Stream&#91;plugin&#93;&#58; edit log id <882> 
?Debug &#58; Feb 07 23&#58;57&#58;28 AcctServer&#58; Reply packet dump&#58; RPacket&#58; 
Code&#58; 5; ID&#58; 78 
 
?Debug &#58; Feb 07 23&#58;57&#58;28 RadiusSocket&#58; Moving RADIUS packet into send queue 
?Debug &#58; Feb 07 23&#58;57&#58;28 AcctServer&#58; Next... 
?Debug &#58; Feb 07 23&#58;57&#58;28 RadiusSocket&#58; Waiting for RADIUS raw data 
?Debug &#58; Feb 07 23&#58;57&#58;28 RadiusSocket&#58; RADIUS raw data sent 
?Debug &#58; Feb 07 23&#58;57&#58;32 RadiusSocket&#58; RADIUS packet successfully received 
?Debug &#58; Feb 07 23&#58;57&#58;32 RadiusSocket&#58; RADIUS raw data obtained 
?Debug &#58; Feb 07 23&#58;57&#58;32 RADIUS Packet&#58; Size <185>; HDR.Size <185> 
?Debug &#58; Feb 07 23&#58;57&#58;32 AcctServer&#58; Recv... 
?Debug &#58; Feb 07 23&#58;57&#58;32 AcctServer&#58; Packet from <x.x.x.x> packet dump&#58; RPacket&#58; 
Code&#58; 4; ID&#58; 226 
<Vendor&#58; 0; Attr&#58; 1>&#91;10&#93;&#58; 616c656b736173686b61 
<Vendor&#58; 0; Attr&#58; 4>&#91;4&#93;&#58; ac1de5fe 
<Vendor&#58; 0; Attr&#58; 5>&#91;4&#93;&#58; 00000018 
<Vendor&#58; 0; Attr&#58; 6>&#91;4&#93;&#58; 00000002 
<Vendor&#58; 0; Attr&#58; 7>&#91;4&#93;&#58; 00000001 
<Vendor&#58; 0; Attr&#58; 8>&#91;4&#93;&#58; ac1d1d23 
<Vendor&#58; 0; Attr&#58; 9>&#91;4&#93;&#58; ffffffff 
<Vendor&#58; 0; Attr&#58; 31>&#91;12&#93;&#58; 3137322e32392e3232382e33 
<Vendor&#58; 0; Attr&#58; 32>&#91;5&#93;&#58; 616c706861 
<Vendor&#58; 0; Attr&#58; 40>&#91;4&#93;&#58; 00000003 
А вот так выглядит этот блок в 23:59:35 (как раз момент появления второй записи с ИПом 0.0.0.0)

Код: Выделить всё

?Debug &#58; Feb 07 23&#58;59&#58;33 RadiusSocket&#58; Moving RADIUS packet into send queue
?Debug &#58; Feb 07 23&#58;59&#58;33 AcctServer&#58; Next...
?Debug &#58; Feb 07 23&#58;59&#58;33 RadiusSocket&#58; Waiting for RADIUS raw data
?Debug &#58; Feb 07 23&#58;59&#58;33 RadiusSocket&#58; RADIUS raw data sent
?Debug &#58; Feb 07 23&#58;59&#58;34 RADIUS DBA&#58; Correctly interim updated session <836> found. Leave untouched.
?Debug &#58; Feb 07 23&#58;59&#58;34 RADIUS DBA&#58; Correctly interim updated session <837> found. Leave untouched.
?Debug &#58; Feb 07 23&#58;59&#58;34 RADIUS DBA&#58; Correctly interim updated session <842> found. Leave untouched.
?Debug &#58; Feb 07 23&#58;59&#58;34 RADIUS DBA&#58; Correctly interim updated session <850> found. Leave untouched.
?Debug &#58; Feb 07 23&#58;59&#58;34 RADIUS DBA&#58; Correctly interim updated session <857> found. Leave untouched.
?Debug &#58; Feb 07 23&#58;59&#58;34 RADIUS DBA&#58; Correctly interim updated session <861> found. Leave untouched.
?Debug &#58; Feb 07 23&#58;59&#58;34 RADIUS DBA&#58; Correctly interim updated session <866> found. Leave untouched.
?Debug &#58; Feb 07 23&#58;59&#58;34 RADIUS DBA&#58; Correctly interim updated session <869> found. Leave untouched.
?Debug &#58; Feb 07 23&#58;59&#58;34 RADIUS DBA&#58; Correctly interim updated session <879> found. Leave untouched.
?Debug &#58; Feb 07 23&#58;59&#58;34 RADIUS DBA&#58; Not interim updated session <882> found. Dopping it ...
?Debug &#58; Feb 07 23&#58;59&#58;34 RADIUS DBA&#58; Correctly interim updated session <883> found. Leave untouched.
?Debug &#58; Feb 07 23&#58;59&#58;34 RADIUS DBA&#58; Correctly interim updated session <921> found. Leave untouched.
?Debug &#58; Feb 07 23&#58;59&#58;34 RADIUS DBA&#58; Correctly interim updated session <927> found. Leave untouched.
?Debug &#58; Feb 07 23&#58;59&#58;34 RADIUS DBA&#58; Correctly interim updated session <939> found. Leave untouched.
?Debug &#58; Feb 07 23&#58;59&#58;34 RADIUS DBA&#58; Correctly interim updated session <954> found. Leave untouched.
?Debug &#58; Feb 07 23&#58;59&#58;34 RADIUS DBA&#58; Correctly interim updated session <967> found. Leave untouched.
?Debug &#58; Feb 07 23&#58;59&#58;34 RADIUS DBA&#58; Correctly interim updated session <972> found. Leave untouched.
?Debug &#58; Feb 07 23&#58;59&#58;34 RADIUS DBA&#58; Correctly interim updated session <980> found. Leave untouched.
?Debug &#58; Feb 07 23&#58;59&#58;34 RADIUS DBA&#58; Correctly interim updated session <990> found. Leave untouched.
?Debug &#58; Feb 07 23&#58;59&#58;34 RADIUS DBA&#58; Correctly interim updated session <1006> found. Leave untouched.
?Debug &#58; Feb 07 23&#58;59&#58;34 RADIUS DBA&#58; Correctly interim updated session <1010> found. Leave untouched.
?Debug &#58; Feb 07 23&#58;59&#58;34 RADIUS DBA&#58; Correctly interim updated session <1016> found. Leave untouched.
?Debug &#58; Feb 07 23&#58;59&#58;34 RADIUS DBA&#58; Correctly interim updated session <1021> found. Leave untouched.
?Debug &#58; Feb 07 23&#58;59&#58;34 RADIUS DBA&#58; Correctly interim updated session <1024> found. Leave untouched.
?Debug &#58; Feb 07 23&#58;59&#58;34 RADIUS DBA&#58; Correctly interim updated session <1028> found. Leave untouched.
?Debug &#58; Feb 07 23&#58;59&#58;34 RADIUS DBA&#58; Correctly interim updated session <1049> found. Leave untouched.
?Debug &#58; Feb 07 23&#58;59&#58;34 RADIUS DBA&#58; Correctly interim updated session <1057> found. Leave untouched.
?Debug &#58; Feb 07 23&#58;59&#58;34 RADIUS DBA&#58; Correctly interim updated session <1064> found. Leave untouched.
?Debug &#58; Feb 07 23&#58;59&#58;34 RADIUS DBA&#58; Correctly interim updated session <1066> found. Leave untouched.
?Debug &#58; Feb 07 23&#58;59&#58;34 RADIUS DBA&#58; Correctly interim updated session <1081> found. Leave untouched.
?Debug &#58; Feb 07 23&#58;59&#58;34 RADIUS DBA&#58; Correctly interim updated session <1088> found. Leave untouched.
?Debug &#58; Feb 07 23&#58;59&#58;34 RADIUS DBA&#58; Correctly interim updated session <1089> found. Leave untouched.
?Debug &#58; Feb 07 23&#58;59&#58;34 RADIUS DBA&#58; Correctly interim updated session <1090> found. Leave untouched.
?Debug &#58; Feb 07 23&#58;59&#58;34 RADIUS DBA&#58; Correctly interim updated session <1094> found. Leave untouched.
?Debug &#58; Feb 07 23&#58;59&#58;34 RADIUS DBA&#58; Correctly interim updated session <1098> found. Leave untouched.
?Debug &#58; Feb 07 23&#58;59&#58;34 RADIUS DBA&#58; Correctly interim updated session <1101> found. Leave untouched.
?Debug &#58; Feb 07 23&#58;59&#58;34 RADIUS DBA&#58; Correctly interim updated session <1107> found. Leave untouched.
?Debug &#58; Feb 07 23&#58;59&#58;34 RADIUS DBA&#58; Correctly interim updated session <1109> found. Leave untouched.
?Debug &#58; Feb 07 23&#58;59&#58;34 RADIUS DBA&#58; Correctly interim updated session <1113> found. Leave untouched.
?Debug &#58; Feb 07 23&#58;59&#58;34 RADIUS DBA&#58; Correctly interim updated session <1114> found. Leave untouched.
?Debug &#58; Feb 07 23&#58;59&#58;34 RADIUS DBA&#58; Correctly interim updated session <1116> found. Leave untouched.
?Debug &#58; Feb 07 23&#58;59&#58;34 RADIUS DBA&#58; Correctly interim updated session <1118> found. Leave untouched.
?Debug &#58; Feb 07 23&#58;59&#58;34 RADIUS DBA&#58; Correctly interim updated session <1123> found. Leave untouched.
?Debug &#58; Feb 07 23&#58;59&#58;34 RADIUS DBA&#58; Session erase ... login type <4>
?Debug &#58; Feb 07 23&#58;59&#58;34 RADIUS DBA&#58; login type login_pool or login_named_pool
?Debug &#58; Feb 07 23&#58;59&#58;34 RADIUS IPPool&#58; Released <ac1d1d22>
?Debug &#58; Feb 07 23&#58;59&#58;34 RADIUS DBA&#58; login type login_dialup or login_named_pool
 Info &#58; Feb 07 23&#58;59&#58;34 UT&#58; session_addon <0>
 Info &#58; Feb 07 23&#58;59&#58;34 UT&#58; tarification for slink 3186, tr_id 1, mult 0.000000, next 1202403573
 Info &#58; Feb 07 23&#58;59&#58;34 UT&#58; cost info&#58;
 Info &#58; Feb 07 23&#58;59&#58;34 UT&#58; type 0 deny 0 base_cost 1.000000 size 16443 tr_id 1 mult 0.000000 added 0 sum 0.000000
?Debug &#58; Feb 07 23&#58;59&#58;34 RADIUS DBA&#58; Dialup Discount&#58; TR ID 1&#58; 0.000 for 16443 sec
?Debug &#58; Feb 07 23&#58;59&#58;34 RADIUS Stream&#91;plugin&#93;&#58; finish log id <882>
?Debug &#58; Feb 07 23&#58;59&#58;34 RADIUS Stream&#91;plugin&#93;&#58; Account <849> with balance <1234>
?Debug &#58; Feb 07 23&#58;59&#58;34 StreamConnection&#58; Message id <0x2003>, handler returns 0
?Debug &#58; Feb 07 23&#58;59&#58;35 RadiusSocket&#58; RADIUS packet successfully received
?Debug &#58; Feb 07 23&#58;59&#58;35 RadiusSocket&#58; RADIUS raw data obtained
?Debug &#58; Feb 07 23&#58;59&#58;35 RADIUS Packet&#58; Size <181>; HDR.Size <181>
?Debug &#58; Feb 07 23&#58;59&#58;35 AcctServer&#58; Recv...
?Debug &#58; Feb 07 23&#58;59&#58;35 AcctServer&#58; Packet from <x.x.x.x> packet dump&#58; RPacket&#58;
Code&#58; 4; ID&#58; 16
<Vendor&#58; 0; Attr&#58; 1>&#91;4&#93;&#58; 67756c61
<Vendor&#58; 0; Attr&#58; 4>&#91;4&#93;&#58; ac1de5fe
<Vendor&#58; 0; Attr&#58; 5>&#91;4&#93;&#58; 00000029
<Vendor&#58; 0; Attr&#58; 6>&#91;4&#93;&#58; 00000002
<Vendor&#58; 0; Attr&#58; 7>&#91;4&#93;&#58; 00000001
<Vendor&#58; 0; Attr&#58; 8>&#91;4&#93;&#58; ac1d1d22
<Vendor&#58; 0; Attr&#58; 9>&#91;4&#93;&#58; ffffffff
<Vendor&#58; 0; Attr&#58; 31>&#91;14&#93;&#58; 3137322e32392e3232382e323136
<Vendor&#58; 0; Attr&#58; 32>&#91;5&#93;&#58; 616c706861
<Vendor&#58; 0; Attr&#58; 40>&#91;4&#93;&#58; 00000003
<Vendor&#58; 0; Attr&#58; 42>&#91;4&#93;&#58; 0013fbeb
<Vendor&#58; 0; Attr&#58; 43>&#91;4&#93;&#58; 003ef935
<Vendor&#58; 0; Attr&#58; 44>&#91;13&#93;&#58; 323338373133322d76706e3432
<Vendor&#58; 0; Attr&#58; 45>&#91;4&#93;&#58; 00000001
<Vendor&#58; 0; Attr&#58; 46>&#91;4&#93;&#58; 0000403b
<Vendor&#58; 0; Attr&#58; 47>&#91;4&#93;&#58; 00006c19
<Vendor&#58; 0; Attr&#58; 48>&#91;4&#93;&#58; 0000818f
<Vendor&#58; 0; Attr&#58; 50>&#91;13&#93;&#58; 323338373133322d76706e3432
<Vendor&#58; 0; Attr&#58; 51>&#91;4&#93;&#58; 00000001
<Vendor&#58; 0; Attr&#58; 52>&#91;4&#93;&#58; 00000000
<Vendor&#58; 0; Attr&#58; 53>&#91;4&#93;&#58; 00000000
<Vendor&#58; 0; Attr&#58; 61>&#91;4&#93;&#58; 00000005

?Debug &#58; Feb 07 23&#58;59&#58;35 RADIUS DBA&#58; NAS found. Data size <0>
?Debug &#58; Feb 07 23&#58;59&#58;35 AcctServer&#58; Acct packet with session ID&#58; 2387132-vpn42
?Debug &#58; Feb 07 23&#58;59&#58;35 RADIUS DBA&#58; NAS found. Data size <0>
?Debug &#58; Feb 07 23&#58;59&#58;35 AcctServer&#58; Acct-Interim-Update packet
?Debug &#58; Feb 07 23&#58;59&#58;35 AcctServer&#58; Acct-Start&#58; User <test>
?Debug &#58; Feb 07 23&#58;59&#58;35 AcctServer&#58; Updating session <2387132-vpn42> input/output octets <1309675>/<4127029> session time <16443>
?Debug &#58; Feb 07 23&#58;59&#58;35 RADIUS DBA&#58; Info for login <test> found. type <2>
?Debug &#58; Feb 07 23&#58;59&#58;35 RADIUS DBA&#58; info for user found. type <4> info addr <136452096>
?Debug &#58; Feb 07 23&#58;59&#58;35 RADIUS DBA&#58; search_user_info return info <136452096>
?Debug &#58; Feb 07 23&#58;59&#58;35 RADIUS DBA&#58; search_user_info return valid info
?Debug &#58; Feb 07 23&#58;59&#58;35 RADIUS IPPool&#58; Bind <0> &#58; <ac1d1d20>
?Debug &#58; Feb 07 23&#58;59&#58;35 RADIUS DBA&#58; Setting interim interval <120> for session id <2387132-vpn42>
?Debug &#58; Feb 07 23&#58;59&#58;35 RADIUS DBA&#58; Calling send_session_log_init_sync ...
?Debug &#58; Feb 07 23&#58;59&#58;35 RADIUS Stream&#91;plugin&#93;&#58; send_session_log_init_sync
?Debug &#58; Feb 07 23&#58;59&#58;35 RADIUS Stream&#91;plugin&#93;&#58; init log id <1126>
?Debug &#58; Feb 07 23&#58;59&#58;35 RADIUS DBA&#58; Interim updating session <2387132-vpn42> with timestamp <1202403575>
?Debug &#58; Feb 07 23&#58;59&#58;35 RADIUS Stream&#91;plugin&#93;&#58; edit log id <1126>
?Debug &#58; Feb 07 23&#58;59&#58;35 AcctServer&#58; Reply packet dump&#58; RPacket&#58;
Code&#58; 5; ID&#58; 16 
Настораживает строка

Код: Выделить всё

?Debug &#58; Feb 07 23&#58;59&#58;34 RADIUS DBA&#58; Not interim updated session <882> found. Dopping it ... 
и далее

Код: Выделить всё

?Debug &#58; Feb 07 23&#58;59&#58;35 RADIUS DBA&#58; Info for login <test> found. type <2> 
?Debug &#58; Feb 07 23&#58;59&#58;35 RADIUS DBA&#58; info for user found. type <4> info addr <136452096> 
?Debug &#58; Feb 07 23&#58;59&#58;35 RADIUS DBA&#58; search_user_info return info <136452096> 
?Debug &#58; Feb 07 23&#58;59&#58;35 RADIUS DBA&#58; search_user_info return valid info 
?Debug &#58; Feb 07 23&#58;59&#58;35 RADIUS IPPool&#58; Bind <0> &#58; <ac1d1d20>
Строка RADIUS IPPool: Bind <0> : <ac1d1d20> судя по всему и освобождает ИП x.x.x.34 и дает пользователю ИП "никакой".

НАСу же ничего не приходит и пользователь продолжает спокойнинько висеть на линии и пользовать интернет.

Кроме того,в DIAL-UP отчете вижу следующее:

Код: Выделить всё

Дата начала&#58; 00&#58;02&#58;20
Дата окончания&#58; 00&#58;&#58;18&#58;49
Полученый IP&#58; x.x.x.34      ------------!!!
ID сессии NAS&#58; 2403738-VPN14
Логин&#58; test2
Принято&#58; 12 &#40;пока линковались успел посчитать&#41;
в логах же MPD в это время появляется следующее:

Код: Выделить всё

mpd&#58; &#91;vpn14&#93; AUTH&#58; Accounting-Thread started
mpd&#58; &#91;vpn14&#93; RADIUS&#58; RadiusAccount for&#58; test2 &#40;Type&#58; 1&#41;
mpd&#58; &#91;vpn14&#93; rec'd unexpected protocol CCP, rejecting
mpd&#58; &#91;vpn14&#93; IPCP&#58; rec'd Configure Request #5 &#40;Req-Sent&#41;
mpd&#58; IPADDR 0.0.0.0
mpd&#58; NAKing with x.x.x.34
mpd&#58; PRIDNS 0.0.0.0
mpd&#58; NAKing with x.x.x.x
mpd&#58; PRINBNS 0.0.0.0
mpd&#58; SECDNS 0.0.0.0
mpd&#58; SECNBNS 0.0.0.0
mpd&#58; &#91;vpn14&#93; IPCP&#58; SendConfigRej #5
mpd&#58; PRINBNS 0.0.0.0
mpd&#58; SECDNS 0.0.0.0
mpd&#58; SECNBNS 0.0.0.0
mpd&#58; &#91;vpn14&#93; IPCP&#58; rec'd Configure Reject #13 &#40;Req-Sent&#41;
mpd&#58; COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
mpd&#58; &#91;vpn14&#93; IPCP&#58; SendConfigReq #14
mpd&#58; IPADDR x.x.x.x
mpd&#58; &#91;vpn14&#93; IPCP&#58; rec'd Configure Request #6 &#40;Req-Sent&#41;
mpd&#58; IPADDR 0.0.0.0
mpd&#58; NAKing with x.x.x.34
mpd&#58; PRIDNS 0.0.0.0
mpd&#58; NAKing with x.x.x.x
mpd&#58; &#91;vpn14&#93; IPCP&#58; SendConfigNak #6
mpd&#58; IPADDR x.x.x.34
mpd&#58; PRIDNS x.x.x.x
mpd&#58; &#91;vpn14&#93; IPCP&#58; rec'd Configure Ack #14 &#40;Req-Sent&#41;
mpd&#58; IPADDR x.x.x.x
mpd&#58; &#91;vpn14&#93; IPCP&#58; state change Req-Sent --> Ack-Rcvd
mpd&#58; &#91;vpn14&#93; IPCP&#58; rec'd Configure Request #7 &#40;Ack-Rcvd&#41;
mpd&#58; IPADDR x.x.x.34
mpd&#58; x.x.x.34 is OK
mpd&#58; PRIDNS x.x.x.x
mpd&#58; &#91;vpn14&#93; IPCP&#58; SendConfigAck #7
mpd&#58; IPADDR x.x.x.34
mpd&#58; PRIDNS x.x.x.x
mpd&#58; &#91;vpn14&#93; IPCP&#58; state change Ack-Rcvd --> Opened
mpd&#58; &#91;vpn14&#93; IPCP&#58; LayerUp
mpd&#58; x.x.x.x -> x.x.x.34
mpd&#58; &#91;vpn14&#93; IFACE&#58; Up event
mpd&#58; &#91;vpn14&#93; IFACE&#58; Adding IPv4 address to ng14 failed&#58; File exists
mpd&#58; &#91;vpn14&#93; RADIUS&#58; rec'd RAD_ACCOUNTING_RESPONSE for user test2
Как видно,НАС получает от радиуса ип х.х.х.34 и пытается присвоить его подключающемуся пользователю,но не может, т.к. такой ИП все еще используется на другом интерфейсе. Об этом свидетельствует запись

Код: Выделить всё

mpd&#58; &#91;vpn14&#93; IFACE&#58; Adding IPv4 address to ng14 failed&#58; File exists
В итоге получается: у пользователя test ИП биллинг отлинковал, пользователю test2 прилинковал. Ползователь test продолжает висеть на линии и качать интернет. А трафик записывается пользователю test2 и соответственно ему же и тарифицируется.
При перезагрузке НАСа проблема уходит до следующего раза.
Проблема явно не в MPD. Потому что поменяно уже 3 версии, а проблема не уходит.Появляется случайным образом.
Раньше все прекрасно работало на протяжении более полугода.
Ума не приложу куда копать :(

Lelik85
Сообщения: 76
Зарегистрирован: Вт апр 18, 2006 16:14

Сообщение Lelik85 »

Проблема так и не Решилась
:(

Lelik85
Сообщения: 76
Зарегистрирован: Вт апр 18, 2006 16:14

Сообщение Lelik85 »

Подниму.
Мож чего всплывет все-таки

steckovski
Сообщения: 31
Зарегистрирован: Сб июл 26, 2008 11:58

Сообщение steckovski »

Решили проблему? У меня такая же. Реально адреса пользователям выдаются из диапозона 192.168.100.0/27, а в настройках забито 192.168.100.0/24. Кто-нибудь разобрался с данной проблемой?

Аватара пользователя
Chris
Сообщения: 2323
Зарегистрирован: Чт июн 02, 2005 14:08
Откуда: 33 76 77 71 86 37 98

Сообщение Chris »

session limit, interim update... смотрим их...

drained
Сообщения: 12
Зарегистрирован: Ср май 28, 2008 09:11

Сообщение drained »

Кто нибудь разобрался с данной проблемой?

shoorickello
Сообщения: 134
Зарегистрирован: Ср июн 29, 2005 13:08

Сообщение shoorickello »

Я разобрался, теперь у меня адреса выдаёт FreeRADIUS.

Ещё относительно помог сброс сессий, длящихся более 23 часов. Нетап радиус забывает о выданных адресах из пула спустя сутки. В хотлайне ничем так и не помогли.

JAO
Сообщения: 1153
Зарегистрирован: Вт дек 11, 2007 08:17

Сообщение JAO »

Мда. Этому радиусу VPN доверять явно не стоит, я не ошибся, поставив FreeRADIUS. Его удел - телефония и Dialup.

drained
Сообщения: 12
Зарегистрирован: Ср май 28, 2008 09:11

Сообщение drained »

Интересно что ответят в хотлайне, написал им письмо. И куда пошлют :)

mikkey finn
Сообщения: 1612
Зарегистрирован: Пт ноя 10, 2006 15:23

Сообщение mikkey finn »

можно пулы отдать на откуп NAS-у. Mpd5.x умеет выдавать адреса из своего пула, так что надо просто откатать...

Ответить