forum.bitel.ru • Просмотр темы - Проблемы какие-то, навалились прям :)

Сообщения без ответов | Активные темы

Список форумов » BGBilling » Модули Интернета » Модуль DialUp (VPN)

Часовой пояс: UTC + 5 часов [ Летнее время ]

Проблемы какие-то, навалились прям :)

Страница 1 из 1

[ Сообщений: 28 ]

Версия для печати

Пред. тема | След. тема

Автор

Сообщение

Заголовок сообщения: Проблемы какие-то, навалились прям :)

Добавлено: 18 янв 2008, 16:22

Версия биллинга 4.3, радиус version 4.3 build 28 from 16.11.2007 09:42:3. Система Gentoo Linux. NAS-сервера - mpd-3.18.
1. Первая проблема, только что заметил просто.
В логах радиуса:

Код:

INFO   18.01.2008 16:56:00  SNMP response  [ SNMP1, host=192.168.0.90, msg=uk.co.westhawk.snmp.stack.AgentException cannot be cast to uk.co.westhawk.snmp.stack.varbind, recived object=uk.co.westhawk.snmp.stack.AgentException: Timed out ]

SNMP-траффик между хостами идет.

Код:

57:18.322846 IP (tos 0x0, ttl  64, id 0, offset 0, flags [DF], length: 73) 192.168.0.110.32780 > 192.168.0.90.snmp: [udp sum ok]  { SNMPv2c C=qwerty { GetRequest(30) R=15110424  E:2021.255.19 } }

57:20.319071 IP (tos 0x0, ttl  64, id 38178, offset 0, flags [none], length: 83) 192.168.0.90.snmp > 192.168.0.110.32780:  { SNMPv2c C=qwerty { GetResponse(39) R=15110289  E:2021.255.3="login" } }

2. Проблема: ровно в 00.00 каждый день людей отключает.
По логам радиуса в этот момент ничего существенного:

Код:

15 23:52:11
Type=AUTHENTICATION_REQUEST
Attributes:
User-Name=kosmo1_103
NAS-Identifier=nas
NAS-IP-Address=192.168.0.110
NAS-Port=21
Service-Type=2
Framed-Protocol=1
Calling-Station-Id=192.168.6.37 / \u40unknown\u41 / \u40unknown\u41
NAS-Port-Type=5
MS-CHAP2-Response=\u1\u0\u63\u164\u63xT8Yb\u63\u6\u63\u0\u164z\u61\u164\u0\u0\u0\u0\u0\u0\u0\u0_\u28T\u63\u23\u9\u3\u638_P7\u63t\u63C\u63B\u91\u63\u27\u63\u63C
MS-CHAP-Challenge=\u187\u30hg\u15\u41IY\u26\u63\u63\T\u7\u25W

15 23:52:11
Type=AUTHENTICATION_ACCEPT
Process time:17
Attributes:
Acct-Interim-Interval=20
Service-Type=2
Framed-Protocol=1
Framed-IP-Address=62.33.201.35
MS-MPPE-Send-Key=\u63\u0\u63\u63\u23\u63\u63\u94#\u63\u63\u63\u22\u127\u183\u63\u183\u63L\u63\u63\u63\u634\u63\u14\u36\u61\u63l\u63\u174X\u63
MS-MPPE-Recv-Key=\u63\u0\u63\u38\u63\u163\u63\u63\u2\u63\u63T\u63\u63c\u63\u173\u63\u37\u63\u63C\u63l\u18C\u63\u63\u123:n\u5\u63
MS-CHAP2-Success=\u63S\u61172116D39CB321693C409EC6C7E7664D03F61E2D
MS-MPPE-Encryption-Types=4
MS-MPPE-Encryption-Policy=1

15 23:52:11
Type=ACCOUNTING_REQUEST
Attributes:
User-Name=kosmo1_103
NAS-Identifier=nas
NAS-IP-Address=192.168.0.110
NAS-Port=21
Service-Type=2
Framed-Protocol=1
Framed-IP-Address=62.33.201.35
Acct-Status-Type=1
Acct-Session-Id=416027-pptp021
Acct-Authentic=1
Acct-Link-Count=1
Acct-Multi-Session-Id=416027-pptp021
NAS-Port-Type=5
Calling-Station-Id=192.168.6.37 / \u40unknown\u41 / \u40unknown\u41

16 00:01:24
Type=ACCOUNTING_REQUEST
Attributes:
User-Name=kosmo1_103
NAS-Identifier=nas
NAS-IP-Address=192.168.0.110
NAS-Port=21
Service-Type=2
Framed-Protocol=1
Acct-Input-Octets=213919
Framed-IP-Address=62.33.201.35
Acct-Output-Octets=698518
Acct-Status-Type=2
Acct-Session-Time=555
Acct-Input-Packets=1351
Acct-Session-Id=416027-pptp021
Acct-Authentic=1
Acct-Link-Count=1
Acct-Multi-Session-Id=416027-pptp021
Acct-Terminate-Cause=10
Acct-Output-Packets=1066
Acct-Output-Gigawords=0
Acct-Input-Gigawords=0
NAS-Port-Type=5

То есть, выглядит все так, как если бы клиент сам отключился.

Код:

INFO   16.01.2008 00:01:24  [ LS-00115; kosmo1_103; 31521 ] DialUpNASConnection stoppingConnection
INFO   16.01.2008 00:01:24  [ LS-00115; kosmo1_103; 31521 ] DialUpNASConnection has stop Packet => true
INFO   16.01.2008 00:01:24  [ LS-00115; kosmo1_103; 31521 ] DialUpNASConnection set STATUS=3
INFO   16.01.2008 00:01:24  [ LS-00115; kosmo1_103; 31521 ] DialUpNASConnection sessionTime => 555
INFO   16.01.2008 00:02:14  [ LS-00115; kosmo1_103; 33956 ] DialUpNASConnection startConnection mode=1
INFO   16.01.2008 00:02:14  [ LS-00115; kosmo1_103; 33956 ] DialUpNASConnection set STATUS=1
INFO   16.01.2008 00:02:53  [ LS-00115; kosmo1_103; 33956 ] DialUpNASConnection update connection..

Но клиент ничего не делает. Но ровно в 00.00, плюс\минус минута\две. Такое началось, когда я обновил радиус. На 4.2 такого не было. Думаю, обновить его еще раз? Настройки собственно тоже никто не менял. Может что с тарифом, но его никто не трогал. Я читал, что у вас есть сброс раз в месяц, но такого не настраивал.

3. Проблема улетания в большой минус
Также, на 4.2 было все нормально в принципе, если у клиента не специфичный режим работы, позволяющий уходить в минус, то улетал он максимум в 20 рублей, в ipcad я настроил длительность каждого потока 10 секунд, чтоб много не качалось. А щас улетел в минус. Есть один момент: в NAS слишком много открытых файлов становится в определенный момент и дескрипторов не хватает, периодически приходится ребутать машину, увеличить дескрипторы можно, но суть в том, что это могло повлиять на работу коллектора и он позволил netflow-потоку не останавливаться, пока не скачается файл. Это чисто предположение.
4. Проблема, которую я описывал в соседней ветке. http://bgbilling.ru/forum/viewtopic.php?t=562
Наложение даты сессий входа\выхода абонента. Думаю где-то прикол в настройках NAS, только понять не могу где, т.к. все считает верно, и суммы верно, но только на этом NAS (РРРоЕ), на другом NAS (VPN) все нормально.
5. Некоторые клиенты на NAS (PPPoE) не обсчитываются совсем
Как будет лог в радиусе этого соединения, скину. На VPN все нормально.
P.S. Пойду проверять настройки. Какие нужны логи могу добавить. Жду помощи.

Вернуться к началу

Заголовок сообщения:

Добавлено: 18 янв 2008, 17:21

Нашел лог по 5 проблеме:

Код:

10 15:57:57
Type=AUTHENTICATION_REQUEST
Attributes:
User-Name=bakunin2
NAS-Identifier=amber
CHAP-Password=\u1\u0\u63_\u36#4\u63\u63\u123\u63\u63\u63\u63\u40\u636
NAS-Port=32
Service-Type=2
Framed-Protocol=1
Calling-Station-Id=0013d3a99d59
NAS-Port-Type=5
CHAP-Challenge=\u187\u30h
C?,\u166}???\u4\u27hy??\u29w??sd??x?(L\u3?

10 15:57:57
Type=AUTHENTICATION_ACCEPT
Process time:19
Attributes:
Acct-Interim-Interval=20
Service-Type=2
Framed-Protocol=1
Framed-IP-Address=83.234.37.166

10 15:57:57
Type=ACCOUNTING_REQUEST
Attributes:
User-Name=bakunin2
NAS-Identifier=amber
NAS-Port=32
Service-Type=2
Framed-Protocol=1
Framed-IP-Address=83.234.37.166
Acct-Status-Type=1
Acct-Session-Id=9955477-pppoe32
Acct-Authentic=1
Acct-Link-Count=1
Acct-Multi-Session-Id=9955477-pppoe32
NAS-Port-Type=5
Calling-Station-Id=0013d3a99d59

10 19:47:01
Type=ACCOUNTING_REQUEST
Attributes:
User-Name=bakunin2
NAS-Identifier=amber
NAS-Port=32
Service-Type=2
Framed-Protocol=1
Acct-Input-Octets=1402091
Framed-IP-Address=83.234.37.166
Acct-Output-Octets=6721344
Acct-Status-Type=2
Acct-Session-Time=21492
Acct-Input-Packets=10189
Acct-Session-Id=9955477-pppoe32
Acct-Authentic=1
Acct-Link-Count=1
Acct-Multi-Session-Id=9955477-pppoe32
Acct-Terminate-Cause=1
Acct-Output-Packets=11008
Acct-Output-Gigawords=0
Acct-Input-Gigawords=0
NAS-Port-Type=5
Calling-Station-Id=0013d3a99d59

У клиента в отчетах все по нулям.

Вернуться к началу

Администратор

Заголовок сообщения:

Добавлено: 21 янв 2008, 11:53

Разработчик

Зарегистрирован: 27 ноя 2006, 20:36
Сообщения: 5715
Карма: 93

1. Последнее обновление RADIUS сервера должно помочь, там была проблема с неравномерным распределением отправляемых SNMP запросов, они терялись.
2. Нужно бы пораньше строки из connection.log по данной сессии. Как определяете что отключает RADIUS? Если есть запросы на сброс - они там логируются.
3. Нужно смотреть приходят ли потоки от ipcad по данному соединению, можете установить лог netflow в режим DEBUG если не очень большие объемы и понаблюдать как приходит статистика по IP сессии.
4. По наложению я отписал вам - нужно RADIUS логи этих 2х сессий, возможно что авторизация второй сессии приходит раньше чем стоп первой.
5. Необходимо connection.log по данному соединению вытащить.. И опять же, проверить что netflow статистика приходит (см. 3).

Вернуться к началу

Заголовок сообщения:

Добавлено: 25 янв 2008, 10:43

1. Не трогал радиус, само прошло...странно как-то, пока подожду рецидива. Но возникли подозрительные надписи:

Код:

INFO   24.01.2008 20:46:32  [ LS-00289; kosmo20_56; 6957 ] No close calculate period..
INFO   24.01.2008 20:48:02  [ LS-00791; sov90_26; 80889 ] No close calculate period..
INFO   24.01.2008 21:04:47  [ LS-00227; kalin24_179; 67243 ] No close calculate period..
INFO   24.01.2008 21:23:47  [ LS-00888 ; kalin20_73; 66551 ] No close calculate period..
INFO   24.01.2008 22:09:34  [ LS-00439; orlova30a_3; 13395 ] No close calculate period..
INFO   25.01.2008 00:19:00  [ LS-01033 ; kalin25_15; 80236 ] No close calculate period..
INFO   25.01.2008 00:23:05  [ LS-00125; gork1_25; 64922 ] No close calculate period..
INFO   25.01.2008 07:07:33  [ LS-00169; yubil8_62; 31599 ] No close calculate period..
INFO   25.01.2008 07:12:33  [ LS-00169; yubil8_62; 31599 ] No close calculate period..
INFO   25.01.2008 10:55:38  [ LS-00075 ; sov98_194; 17209 ] No close calculate period..
INFO   25.01.2008 10:55:58  [ LS-00075 ; sov98_194; 17209 ] No close calculate period..
INFO   25.01.2008 10:56:18  [ LS-00075 ; sov98_194; 17209 ] No close calculate period..
INFO   25.01.2008 10:56:38  [ LS-00075 ; sov98_194; 17209 ] No close calculate period..
INFO   25.01.2008 10:56:58  [ LS-00075 ; sov98_194; 17209 ] No close calculate period..
INFO   25.01.2008 10:57:18  [ LS-00075 ; sov98_194; 17209 ] No close calculate period..
INFO   25.01.2008 10:57:38  [ LS-00075 ; sov98_194; 17209 ] No close calculate period..
INFO   25.01.2008 10:57:58  [ LS-00075 ; sov98_194; 17209 ] No close calculate period..
INFO   25.01.2008 10:58:18  [ LS-00075 ; sov98_194; 17209 ] No close calculate period..
INFO   25.01.2008 10:58:38  [ LS-00075 ; sov98_194; 17209 ] No close calculate period..
INFO   25.01.2008 10:58:58  [ LS-00075 ; sov98_194; 17209 ] No close calculate period..
INFO   25.01.2008 10:59:18  [ LS-00075 ; sov98_194; 17209 ] No close calculate period..
INFO   25.01.2008 10:59:38  [ LS-00075 ; sov98_194; 17209 ] No close calculate period..
INFO   25.01.2008 10:59:58  [ LS-00075 ; sov98_194; 17209 ] No close calculate period..
INFO   25.01.2008 11:00:18  [ LS-00075 ; sov98_194; 17209 ] No close calculate period..

А весь лог выглядит как-то странно:

Код:

INFO   25.01.2008 11:00:08  [ LS-00075 ; sov98_194; 17209 ] sendKillRequest
INFO   25.01.2008 11:00:08  [ LS-00075 ; sov98_194; 17209 ] SNMP reset request: set 1.3.6.1.4.1.2021.255.1 i 24
INFO   25.01.2008 11:00:13  [ LS-00075 ; sov98_194; 17209 ] sendKillRequest
INFO   25.01.2008 11:00:13  [ LS-00075 ; sov98_194; 17209 ] SNMP reset request: set 1.3.6.1.4.1.2021.255.1 i 24
INFO   25.01.2008 11:00:18  [ LS-00075 ; sov98_194; 17209 ] sendKillRequest
INFO   25.01.2008 11:00:18  [ LS-00075 ; sov98_194; 17209 ] Set connection to KILL
INFO   25.01.2008 11:00:18  [ LS-00075 ; sov98_194; 17209 ] DialUpNASConnection update connection..
INFO   25.01.2008 11:00:18  [ LS-00075 ; sov98_194; 17209 ] No close calculate period..
INFO   25.01.2008 11:00:18  [ LS-00075 ; sov98_194; 17209 ] Set connection to KILL
INFO   25.01.2008 11:00:18  [ LS-00075 ; sov98_194; 17209 ] DialUpNASConnection killing connection after UPDATE
INFO   25.01.2008 11:00:18  [ LS-00075 ; sov98_194; 17209 ] DialUpNASConnection set STATUS=1

Попробую обновить радиус и поглядеть.
2. Возьмем другой лог радиуса, т.к. затирается в радиусе старые логи.

Код:

24 22:13:24
Type=AUTHENTICATION_REQUEST
Attributes:
User-Name=yubil8_62
NAS-Identifier=nas.tehset.ru
NAS-IP-Address=192.168.0.110
NAS-Port=14
Service-Type=2
Framed-Protocol=1
Calling-Station-Id=192.168.5.56 / \u40unknown\u41 / \u40unknown\u41
NAS-Port-Type=5
MS-CHAP2-Response=\u1\u0p9.\u9e\u12\u63i\u63O\u61\u3\u63\u174\u63s\u0\u0\u0\u0\u0\u0\u0\u0R\u37m\u63d0\u20\u63\u23\u31\u3.\u63\u21I\u63\u63\u63\u63\u63\u63\u91g\u63
MS-CHAP-Challenge=\u187\u30h\u25\u63\u38\u19\u63B\u63\u63A\u18O\u183\u40

24 22:13:24
Type=AUTHENTICATION_ACCEPT
Process time:31
Attributes:
Acct-Interim-Interval=20
Service-Type=2
Framed-Protocol=1
Framed-IP-Address=62.33.201.112
MS-MPPE-Send-Key=\u63\u0\u40\u37\u63\u63\u17\u63\u24\u63\u59\u63\u63\u63t\u63Yd\u63\u63\u13b\u63\u63\u5\u20\u63\u30\u1714\u63\u63\u36U
MS-MPPE-Recv-Key=\u63\u0\u40\u63\u169#\u36\u61\u63\u63\u63\u63\u63\u59\u25I\u41ID\u63
DL\u17X\u6??«???
MS-CHAP2-Success=\u63S\u6102A19F1BF00D8A5756E14FEFF1FB5C6F5DFB36F1
MS-MPPE-Encryption-Types=4
MS-MPPE-Encryption-Policy=1

24 22:13:24
Type=ACCOUNTING_REQUEST
Attributes:
User-Name=yubil8_62
NAS-Identifier=nas.tehset.ru
NAS-IP-Address=192.168.0.110
NAS-Port=14
Service-Type=2
Framed-Protocol=1
Framed-IP-Address=62.33.201.112
Acct-Status-Type=1
Acct-Session-Id=1187623-pptp014
Acct-Authentic=1
Acct-Link-Count=1
Acct-Multi-Session-Id=1187623-pptp014
NAS-Port-Type=5
Calling-Station-Id=192.168.5.56 / \u40unknown\u41 / \u40unknown\u41

25 00:01:27
Type=ACCOUNTING_REQUEST
Attributes:
User-Name=yubil8_62
NAS-Identifier=nas.tehset.ru
NAS-IP-Address=192.168.0.110
NAS-Port=14
Service-Type=2
Framed-Protocol=1
Acct-Input-Octets=734115
Framed-IP-Address=62.33.201.112
Acct-Output-Octets=5729409
Acct-Status-Type=2
Acct-Session-Time=6485
Acct-Input-Packets=5541
Acct-Session-Id=1187623-pptp014
Acct-Authentic=1
Acct-Link-Count=1
Acct-Multi-Session-Id=1187623-pptp014
Acct-Terminate-Cause=10
Acct-Output-Packets=6602
Acct-Output-Gigawords=0
Acct-Input-Gigawords=0
NAS-Port-Type=5

В биллинге выглядит все так, как-будто клиент сам инициировал отключение.
Логи NAS по этому соединению:

Код:

Jan 24 23:58:06 nas mpd: [pptp014] RADIUS: RadiusAddServer Adding 192.168.0.110
Jan 24 23:58:06 nas mpd: [pptp014] RADIUS: RadiusAccount: Sending accounting data (Type: 3)
Jan 24 23:58:06 nas mpd: [pptp014] RADIUS: RadiusSendRequest: RAD_ACCOUNTING_RESPONSE for user yubil8_62
Jan 24 23:58:26 nas mpd: [pptp014] RADIUS: RadiusAcctUpdate: Sending Accounting Update
Jan 24 23:58:26 nas mpd: [pptp014] RADIUS: RadiusAccount for: yubil8_62
Jan 24 23:58:26 nas mpd: [pptp014] RADIUS: RadiusAddServer Adding 192.168.0.110
Jan 24 23:58:26 nas mpd: [pptp014] RADIUS: RadiusAccount: Sending accounting data (Type: 3)
Jan 24 23:58:26 nas mpd: [pptp014] RADIUS: RadiusSendRequest: RAD_ACCOUNTING_RESPONSE for user yubil8_62
Jan 24 23:58:46 nas mpd: [pptp014] RADIUS: RadiusAcctUpdate: Sending Accounting Update
Jan 24 23:58:46 nas mpd: [pptp014] RADIUS: RadiusAccount for: yubil8_62
Jan 24 23:58:46 nas mpd: [pptp014] RADIUS: RadiusAddServer Adding 192.168.0.110
Jan 24 23:58:46 nas mpd: [pptp014] RADIUS: RadiusAccount: Sending accounting data (Type: 3)
Jan 24 23:58:46 nas mpd: [pptp014] RADIUS: RadiusSendRequest: RAD_ACCOUNTING_RESPONSE for user yubil8_62
Jan 24 23:59:06 nas mpd: [pptp014] RADIUS: RadiusAcctUpdate: Sending Accounting Update
Jan 24 23:59:06 nas mpd: [pptp014] RADIUS: RadiusAccount for: yubil8_62
Jan 24 23:59:06 nas mpd: [pptp014] RADIUS: RadiusAddServer Adding 192.168.0.110
Jan 24 23:59:06 nas mpd: [pptp014] RADIUS: RadiusAccount: Sending accounting data (Type: 3)
Jan 24 23:59:06 nas mpd: [pptp014] RADIUS: RadiusSendRequest: RAD_ACCOUNTING_RESPONSE for user yubil8_62
Jan 24 23:59:26 nas mpd: [pptp014] RADIUS: RadiusAcctUpdate: Sending Accounting Update
Jan 24 23:59:26 nas mpd: [pptp014] RADIUS: RadiusAccount for: yubil8_62
Jan 24 23:59:26 nas mpd: [pptp014] RADIUS: RadiusAddServer Adding 192.168.0.110
Jan 24 23:59:26 nas mpd: [pptp014] RADIUS: RadiusAccount: Sending accounting data (Type: 3)
Jan 24 23:59:56 nas mpd: [pptp014] RADIUS: RadiusSendRequest: rad_send_request failed No valid RADIUS responses received

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

Код:

Jan 25 00:00:57 nas mpd: pptp13: no reply to EchoRequest after 60 sec
Jan 25 00:00:57 nas mpd: pptp13: killing connection with 192.168.5.56:2943
Jan 25 00:00:57 nas mpd: pptp13-0: killing channel
Jan 25 00:00:57 nas mpd: [pptp014] PPTP call terminated
Jan 25 00:00:57 nas mpd: [pptp014] IFACE: Close event
Jan 25 00:00:57 nas mpd: [pptp014] exec: /usr/local/etc/rc.d/downiface.sh ng14 inet yubil8_62
Jan 25 00:00:57 nas mpd: [pptp014] exec: /sbin/route delete 83.234.37.8 -iface lo0
Jan 25 00:00:57 nas mpd: [pptp014] exec: command returned 256
Jan 25 00:00:57 nas mpd: [pptp014] exec: /sbin/ifconfig ng14 down delete -link0
Jan 25 00:00:57 nas mpd: [pptp014] IPCP: Close event
Jan 25 00:00:57 nas mpd: [pptp014] IPCP: state change Opened --> Closing
Jan 25 00:00:57 nas mpd: [pptp014] IPCP: SendTerminateReq #236
Jan 25 00:00:57 nas mpd: [pptp014] error writing len 8 frame to bypass: Network is down
Jan 25 00:00:57 nas mpd: [pptp014] IPCP: LayerDown
Jan 25 00:00:57 nas mpd: [pptp014] IFACE: Down event
Jan 25 00:00:57 nas mpd: [pptp014] IFACE: Close event

В общем, попробую увеличить параметр set link keep-alive 10 60, может как-то изменится, но думаю BGRadius тут ни при чем.
4. Логи радиуса:
Первая сессия:

Код:

05 11:21:59
Type=AUTHENTICATION_REQUEST
Attributes:
User-Name=stepnoy
NAS-Identifier=amber.region19.ru
CHAP-Password=\u1\u63\u63\u63EJ\u63K\u167\u174P\u6P_X\u63c
NAS-Port=9
Service-Type=2
Framed-Protocol=1
Calling-Station-Id=008048495e5e
NAS-Port-Type=5
CHAP-Challenge=\u187\u30h\u63 \u63\u60\u63\u63\u63\u63\u39\u63\u63\u63\u63\u63_\u63X\u9\u63\u125c\u63

05 11:21:59
Type=AUTHENTICATION_ACCEPT
Process time:53
Attributes:
Acct-Interim-Interval=20
Service-Type=2
Framed-Protocol=1
Framed-IP-Address=83.234.37.196

05 11:21:59
Type=ACCOUNTING_REQUEST
Attributes:
User-Name=stepnoy
NAS-Identifier=amber.region19.ru
NAS-Port=9
Service-Type=2
Framed-Protocol=1
Framed-IP-Address=83.234.37.196
Acct-Status-Type=1
Acct-Session-Id=9506919-pppoe9
Acct-Authentic=1
Acct-Link-Count=1
Acct-Multi-Session-Id=9506919-pppoe9
NAS-Port-Type=5
Calling-Station-Id=008048495e5e

05 11:23:20
Type=ACCOUNTING_REQUEST
Attributes:
User-Name=stepnoy
NAS-Identifier=amber.region19.ru
NAS-Port=9
Service-Type=2
Framed-Protocol=1
Acct-Input-Octets=314395
Framed-IP-Address=83.234.37.196
Acct-Output-Octets=128160
Acct-Status-Type=2
Acct-Session-Time=369
Acct-Input-Packets=703
Acct-Session-Id=9506919-pppoe9
Acct-Authentic=1
Acct-Link-Count=1
Acct-Multi-Session-Id=9506919-pppoe9
Acct-Terminate-Cause=1
Acct-Output-Packets=813
Acct-Output-Gigawords=0
Acct-Input-Gigawords=0
NAS-Port-Type=5
Calling-Station-Id=008048495e5e

Вторая сессия:

Код:

05 11:24:44
Type=AUTHENTICATION_REQUEST
Attributes:
User-Name=stepnoy
NAS-Identifier=amber.region19.ru
CHAP-Password=\u1\u0\u28\u63mU\u94µ\u61\u63\u63\u63\u9\u63\u63\u63H
NAS-Port=12
Service-Type=2
Framed-Protocol=1
Calling-Station-Id=008048495e5e
NAS-Port-Type=5
CHAP-Challenge=\u187\u30h\u63\u63\u63\u124g!\u166\u63\u63eY\u63\u634\u173\u1666\u176\u63\u1e\u171\u63\u169\u63w\u63\u63\u63\u63\u22v\u93\u4\u63\u63\u37\u63\u63d\u63\u8U\u127

05 11:24:44
Type=AUTHENTICATION_ACCEPT
Process time:34
Attributes:
Acct-Interim-Interval=20
Service-Type=2
Framed-Protocol=1
Framed-IP-Address=83.234.37.196

05 11:24:44
Type=ACCOUNTING_REQUEST
Attributes:
User-Name=stepnoy
NAS-Identifier=amber.region19.ru
NAS-Port=12
Service-Type=2
Framed-Protocol=1
Framed-IP-Address=83.234.37.196
Acct-Status-Type=1
Acct-Session-Id=9507084-pppoe12
Acct-Authentic=1
Acct-Link-Count=1
Acct-Multi-Session-Id=9507084-pppoe12
NAS-Port-Type=5
Calling-Station-Id=008048495e5e

05 11:57:45
Type=ACCOUNTING_REQUEST
Attributes:
User-Name=stepnoy
NAS-Identifier=amber.region19.ru
NAS-Port=12
Service-Type=2
Framed-Protocol=1
Acct-Input-Octets=4293290
Framed-IP-Address=83.234.37.196
Acct-Output-Octets=1952060
Acct-Status-Type=2
Acct-Session-Time=69426
Acct-Input-Packets=6606
Acct-Session-Id=9507084-pppoe12
Acct-Authentic=1
Acct-Link-Count=1
Acct-Multi-Session-Id=9507084-pppoe12
Acct-Terminate-Cause=3
Acct-Output-Packets=9274
Acct-Output-Gigawords=0
Acct-Input-Gigawords=0
NAS-Port-Type=5
Calling-Station-Id=008048495e5e

Третья сессия:

Код:

05 11:55:39
Type=AUTHENTICATION_REQUEST
Attributes:
User-Name=stepnoy
NAS-Identifier=amber.region19.ru
CHAP-Password=
?\u22\u166?F\u3?\u26?A??F?0
NAS-Port=9
Service-Type=2
Framed-Protocol=1
Calling-Station-Id=008048495e5e
NAS-Port-Type=5
CHAP-Challenge=\u187\u30hrO\u63\u22\u24\u21w\u63\u63D\u63\u63\u63\u183\u63xU\u63\u63\u63\u59\u37\u63\u63\u63

05 11:55:39
Type=AUTHENTICATION_ACCEPT
Process time:42
Attributes:
Acct-Interim-Interval=20
Service-Type=2
Framed-Protocol=1
Framed-IP-Address=83.234.37.196

05 11:55:39
Type=ACCOUNTING_REQUEST
Attributes:
User-Name=stepnoy
NAS-Identifier=amber.region19.ru
NAS-Port=9
Service-Type=2
Framed-Protocol=1
Framed-IP-Address=83.234.37.196
Acct-Status-Type=1
Acct-Session-Id=9508939-pppoe9
Acct-Authentic=1
Acct-Link-Count=1
Acct-Multi-Session-Id=9508939-pppoe9
NAS-Port-Type=5
Calling-Station-Id=008048495e5e

05 12:38:44
Type=ACCOUNTING_REQUEST
Attributes:
User-Name=stepnoy
NAS-Identifier=amber.region19.ru
NAS-Port=9
Service-Type=2
Framed-Protocol=1
Acct-Input-Octets=2528311
Framed-IP-Address=83.234.37.196
Acct-Output-Octets=20813037
Acct-Status-Type=2
Acct-Session-Time=4524
Acct-Input-Packets=21151
Acct-Session-Id=9508939-pppoe9
Acct-Authentic=1
Acct-Link-Count=1
Acct-Multi-Session-Id=9508939-pppoe9
Acct-Terminate-Cause=1
Acct-Output-Packets=26080
Acct-Output-Gigawords=0
Acct-Input-Gigawords=0
NAS-Port-Type=5
Calling-Station-Id=008048495e5e

В биллинге выглядит вот так:

Код:

stepnoy   2579   05.01.2008 11:21:59   05.01.2008 11:28:08   00:06:09 [369]   0.23868   008048495e5e / *   70090 / 104284 / 0 / 0 / 0 / 0 / 0 / 0
stepnoy   2583   05.01.2008 11:24:44   06.01.2008 06:41:50   19:17:06 [69426]   9.78077   008048495e5e / *   1598391 / 4273294 / 0 / 0 / 8892 / 8736 / 0 / 0
stepnoy   2611   05.01.2008 11:55:39   05.01.2008 13:11:03   01:15:24 [4524]   0.54505   008048495e5e / *   179710 / 238140 / 0 / 0 / 3432 / 1872 / 0 / 0

5. Другую сессию\лог возьмем:

Код:

24 14:21:10
Type=AUTHENTICATION_REQUEST
Attributes:
User-Name=stepnoy
NAS-Identifier=amber.region19.ru
CHAP-Password=\u11 y\u63\u63\u63\u63\u63\u63\u63\u63qbb\u63V
NAS-Port=25
Service-Type=2
Framed-Protocol=1
Calling-Station-Id=008048495e5e
NAS-Port-Type=5
CHAP-Challenge=\u187\u30h_WI\u63Vj\u63\\u9\u40J\u7n\u63\u173y\u63\u40\u63w.*\u19\u63\u21\u63\u63\u63c\u7\u63\u63\u94\u14\u63\u63y

24 14:21:10
Type=AUTHENTICATION_ACCEPT
Process time:185
Attributes:
Acct-Interim-Interval=20
Service-Type=2
Framed-Protocol=1
Framed-IP-Address=83.234.37.196

24 14:21:10
Type=ACCOUNTING_REQUEST
Attributes:
User-Name=stepnoy
NAS-Identifier=amber.region19.ru
NAS-Port=25
Service-Type=2
Framed-Protocol=1
Framed-IP-Address=83.234.37.196
Acct-Status-Type=1
Acct-Session-Id=1159270-pppoe25
Acct-Authentic=1
Acct-Link-Count=1
Acct-Multi-Session-Id=1159270-pppoe25
NAS-Port-Type=5
Calling-Station-Id=008048495e5e

25 09:12:12
Type=ACCOUNTING_REQUEST
Attributes:
User-Name=stepnoy
NAS-Identifier=amber.region19.ru
NAS-Port=25
Service-Type=2
Framed-Protocol=1
Acct-Input-Octets=80738374
Framed-IP-Address=83.234.37.196
Acct-Output-Octets=351797828
Acct-Status-Type=2
Acct-Session-Time=155104
Acct-Input-Packets=329425
Acct-Session-Id=1159270-pppoe25
Acct-Authentic=1
Acct-Link-Count=1
Acct-Multi-Session-Id=1159270-pppoe25
Acct-Terminate-Cause=10
Acct-Output-Packets=389902
Acct-Output-Gigawords=0
Acct-Input-Gigawords=0
NAS-Port-Type=5
Calling-Station-Id=008048495e5e

Для него connection.log:

Код:

INFO   24.01.2008 14:21:10  [ LS-00950; stepnoy; 70820 ] DialUpNASConnection startConnection mode=1
INFO   24.01.2008 14:21:10  [ LS-00950; stepnoy; 70820 ] DialUpNASConnection set STATUS=1
INFO   24.01.2008 14:21:50  [ LS-00950; stepnoy; 70820 ] DialUpNASConnection update connection..
INFO   24.01.2008 14:21:50  [ LS-00950; stepnoy; 70820 ] DialUpNASConnection set STATUS=1
###### Здесь идут апдейты сессии (чтобы все не писать) ########
INFO   24.01.2008 19:05:31  [ LS-00950; stepnoy; 70820 ] Set status SUSPENDED on UpdateWaitSetter, time after last update: 902
INFO   24.01.2008 19:05:31  [ LS-00950; stepnoy; 70820 ] DialUpNASConnection set STATUS=2
INFO   24.01.2008 20:05:30  [ LS-00950; stepnoy; 70820 ] DialUpNASConnection update connection..
INFO   24.01.2008 20:05:30  [ LS-00950; stepnoy; 70820 ] DialUpNASConnection set STATUS=1
INFO   24.01.2008 20:20:32  [ LS-00950; stepnoy; 70820 ] Set status SUSPENDED on UpdateWaitSetter, time after last update: 901
INFO   24.01.2008 20:20:32  [ LS-00950; stepnoy; 70820 ] DialUpNASConnection set STATUS=2
###### Здесь идут апдейты сессии (чтобы все не писать) #######
INFO   25.01.2008 00:12:17  [ LS-00950; stepnoy; 70820 ] DialUpNASConnection update connection..
INFO   25.01.2008 00:12:17  [ LS-00950; stepnoy; 70820 ] DialUpNASConnection set STATUS=1
INFO   25.01.2008 00:13:37  [ LS-00950; stepnoy; 70820 ] DialUpNASConnection update connection..
INFO   25.01.2008 00:13:37  [ LS-00950; stepnoy; 70820 ] DialUpNASConnection set STATUS=1
###### Здесь идут апдейты сессии (чтобы все не писать) #######
INFO   25.01.2008 09:09:33  [ LS-00950; stepnoy; 70820 ] DialUpNASConnection update connection..
INFO   25.01.2008 09:09:33  [ LS-00950; stepnoy; 70820 ] DialUpNASConnection set STATUS=1
INFO   25.01.2008 09:12:09  [ LS-00950; stepnoy; 70820 ] Set connection to KILL
INFO   25.01.2008 09:12:12  [ LS-00950; stepnoy; 70820 ] sendKillRequest
INFO   25.01.2008 09:12:12  [ LS-00950; stepnoy; 70820 ] SNMP reset request: set 1.3.6.1.4.1.2021.255.1 i 25
INFO   25.01.2008 09:12:12  [ LS-00950; stepnoy; 70820 ] DialUpNASConnection stoppingConnection
INFO   25.01.2008 09:12:12  [ LS-00950; stepnoy; 70820 ] DialUpNASConnection has stop Packet => true
INFO   25.01.2008 09:12:12  [ LS-00950; stepnoy; 70820 ] DialUpNASConnection set STATUS=3
INFO   25.01.2008 09:12:12  [ LS-00950; stepnoy; 70820 ] DialUpNASConnection sessionTime => 155104
INFO   25.01.2008 09:12:17  [ LS-00950; stepnoy; 70820 ] sendKillRequest
INFO   25.01.2008 09:12:17  [ LS-00950; stepnoy; 70820 ] SNMP reset request: set 1.3.6.1.4.1.2021.255.1 i 25
INFO   25.01.2008 09:12:17  [ LS-00950; stepnoy; 37863 ] DialUpNASConnection startConnection mode=1
INFO   25.01.2008 09:12:18  [ LS-00950; stepnoy; 37863 ] DialUpNASConnection set STATUS=1
INFO   25.01.2008 09:12:22  [ LS-00950; stepnoy; 70820 ] sendKillRequest
INFO   25.01.2008 09:12:22  [ LS-00950; stepnoy; 70820 ] SNMP reset request: set 1.3.6.1.4.1.2021.255.1 i 25
INFO   25.01.2008 09:12:27  [ LS-00950; stepnoy; 70820 ] sendKillRequest
INFO   25.01.2008 09:12:27  [ LS-00950; stepnoy; 70820 ] Set connection to KILL
INFO   25.01.2008 09:12:57  [ LS-00950; stepnoy; 37863 ] DialUpNASConnection update connection..
INFO   25.01.2008 09:12:57  [ LS-00950; stepnoy; 37863 ] DialUpNASConnection set STATUS=1
######## Последняя запись на сегодня #######
INFO   25.01.2008 11:10:21  [ LS-00950; stepnoy; 37863 ] DialUpNASConnection set STATUS=1
INFO   25.01.2008 11:12:21  [ LS-00950; stepnoy; 37863 ] DialUpNASConnection update connection..
INFO   25.01.2008 11:12:21  [ LS-00950; stepnoy; 37863 ] DialUpNASConnection set STATUS=1

В биллинге выглядит вот так:

Код:

stepnoy   21015   24.01.2008 14:21:10   26.01.2008 09:26:14   43:05:04 [155104]   0.00000   008048495e5e / *   0 / 0 / 0 / 0 / 0 / 0 / 0 / 0

Netflow в дебаг переведу, посмотрю, что получится. Логи наверное из дебага тоже вытащу, чтоб посмотреть.

Вернуться к началу

Заголовок сообщения:

Добавлено: 25 янв 2008, 14:24

Радиус-лог работающей сессии.

Код:

25 13:08:09
Type=AUTHENTICATION_REQUEST
Attributes:
User-Name=pogrugenie
NAS-Identifier=amber.region19.ru
CHAP-Password=\u1#9vT\u160I\u63\u61-+\u63\u160j\\u63a
NAS-Port=31
Service-Type=2
Framed-Protocol=1
Calling-Station-Id=00804840e314
NAS-Port-Type=5
CHAP-Challenge=\u187\u30h\u40Y\u63a\u63G\u63\u31\u63\u41\u63\u63\u63M\u63\u63\u63\u63\u635\u632\u34@\u34\u31\u63g\u63\u63!\u29V\u6\u1278Mv

25 13:08:10
Type=AUTHENTICATION_ACCEPT
Process time:48
Attributes:
Acct-Interim-Interval=20
Service-Type=2
Framed-Protocol=1
Framed-IP-Address=83.234.37.193

25 13:08:10
Type=ACCOUNTING_REQUEST
Attributes:
User-Name=pogrugenie
NAS-Identifier=amber.region19.ru
NAS-Port=31
Service-Type=2
Framed-Protocol=1
Framed-IP-Address=83.234.37.193
Acct-Status-Type=1
Acct-Session-Id=1241289-pppoe31
Acct-Authentic=1
Acct-Link-Count=1
Acct-Multi-Session-Id=1241289-pppoe31
NAS-Port-Type=5
Calling-Station-Id=00804840e314

IP-адрес работает, по крайней мере пингуется.
Netflow в радиусе установлен в дебаге, этот ip не появился. Прикольно конечно, но в чем баг тут...ipcad? У кого такая же проблема была, в чем решение сией проблемы?

Вернуться к началу

Заголовок сообщения:

Добавлено: 25 янв 2008, 16:32

Обновил BGRadius. До и после обновления появилось:
WARN 25.01.2008 17:20:59 Wating for free Thread..
WARN 25.01.2008 17:20:59 Wating for free Thread..
Чего это такое. Ребутал только радиус, сам биллинг не трогал и NAS тоже. Щас переведу радиус в дебаг и погляжу.

Вернуться к началу

Администратор

Заголовок сообщения:

Добавлено: 04 фев 2008, 15:00

Разработчик

Зарегистрирован: 27 ноя 2006, 20:36
Сообщения: 5715
Карма: 93

Сообщение это означает что радиус сервер не успевает ответить на запросы.. Это не гуд. Возможная причина - занята БД. Поставьте последние обновления, в dialup модуле была проблема с очень тяжелым запросом при выборке отчета по сессиям, может это он.
По оставшимся проблемам предлагаю схему поочередного разбора, а то тяжело ориентироваться. Обозначьте одну проблему, будем разбираться.

Вернуться к началу

Заголовок сообщения:

Добавлено: 05 фев 2008, 09:22

Хорошо, модуль обновлю, посмотрим результат.
Остается только одна проблема, наложение времени, при отчетах у клиента. Самое интересное, что в RADIUS-логе, время корректное. Куда копать, где проверить, чтоб отчеты корректно выдавались, люди нервничают

Вернуться к началу

Администратор

Заголовок сообщения:

Добавлено: 05 фев 2008, 12:15

Разработчик

Зарегистрирован: 27 ноя 2006, 20:36
Сообщения: 5715
Карма: 93

Т.е. Acct-Session-Time имеет верную длительность, но при этом окончание одной сессии выходит за начало последующей? Может Start пакет приходит с задержкой, это бы все объяснило..

Вернуться к началу

Заголовок сообщения:

Добавлено: 05 фев 2008, 12:43

Как посмотреть с задержкой или нет прилетает стартовый пакет? connection.log для сесии я выложил, больше нету.

Вернуться к началу

Администратор

Заголовок сообщения:

Добавлено: 05 фев 2008, 13:17

Разработчик

Зарегистрирован: 27 ноя 2006, 20:36
Сообщения: 5715
Карма: 93

Можете вытащить из radius.log пакеты для 2х пересекающихся сессий?

Вернуться к началу

Заголовок сообщения:

Добавлено: 05 фев 2008, 13:31

Это имеете ввиду?
Сессии:

Код:

stepnoy   7324   10.01.2008 14:16:07   11.01.2008 14:44:12   24:28:05 [88085]   10.27172   008048495e5e / *   4487793 / 617861 / 0 / 0 / 1092 / 1092 / 0 / 0

stepnoy   7331   10.01.2008 14:23:42   10.01.2008 16:28:02   02:04:20 [7460]   165.18436   008048495e5e / *   72170252 / 8191352 / 78 / 0 / 8892 / 8580 / 0 / 0

Вот явное пересечение. Логи RADIUS:
Первая сессия:

Код:

10 14:16:07
Type=AUTHENTICATION_REQUEST
Attributes:
User-Name=stepnoy
NAS-Identifier=amber.region19.ru
CHAP-Password=\u1z\u93\u63\u63\u63\u63\u19/\u63n\u63\u172\u169K\u36
NAS-Port=27
Service-Type=2
Framed-Protocol=1
Calling-Station-Id=008048495e5e
NAS-Port-Type=5
CHAP-Challenge=\u187\u30hb\u63\u63\u63Q\u9\u6\u36\u127\u20t\u63\u173

10 14:16:07
Type=AUTHENTICATION_ACCEPT
Process time:37
Attributes:
Acct-Interim-Interval=20
Service-Type=2
Framed-Protocol=1
Framed-IP-Address=83.234.37.196

10 14:16:07
Type=ACCOUNTING_REQUEST
Attributes:
User-Name=stepnoy
NAS-Identifier=amber.region19.ru
NAS-Port=27
Service-Type=2
Framed-Protocol=1
Framed-IP-Address=83.234.37.196
Acct-Status-Type=1
Acct-Session-Id=9949367-pppoe27
Acct-Authentic=1
Acct-Link-Count=1
Acct-Multi-Session-Id=9949367-pppoe27
NAS-Port-Type=5
Calling-Station-Id=008048495e5e

10 14:22:25
Type=ACCOUNTING_REQUEST
Attributes:
User-Name=stepnoy
NAS-Identifier=amber.region19.ru
NAS-Port=27
Service-Type=2
Framed-Protocol=1
Acct-Input-Octets=677185
Framed-IP-Address=83.234.37.196
Acct-Output-Octets=4886785
Acct-Status-Type=2
Acct-Session-Time=88085
Acct-Input-Packets=5451
Acct-Session-Id=9949367-pppoe27
Acct-Authentic=1
Acct-Link-Count=1
Acct-Multi-Session-Id=9949367-pppoe27
Acct-Terminate-Cause=1
Acct-Output-Packets=6427
Acct-Output-Gigawords=0
Acct-Input-Gigawords=0
NAS-Port-Type=5
Calling-Station-Id=008048495e5e

Вторая сессия:

Код:

10 14:23:42
Type=AUTHENTICATION_REQUEST
Attributes:
User-Name=stepnoy
NAS-Identifier=amber.region19.ru
CHAP-Password=\u1\u63\u63\u123\u63\u63\u63\u63Kg\u63V\u41Aµ\u63\u63
NAS-Port=5
Service-Type=2
Framed-Protocol=1
Calling-Station-Id=008048495e5e
NAS-Port-Type=5
CHAP-Challenge=\u187\u30h\u21\u63\u63V0\u63\u4\u63\u63\u63\u91\u21De\u63µ\u63\u63\u40\u26\u63B\u63\u19yA\u63\u63+\u63\u63A\\u26\u63\u63\u63\u63\u63

10 14:23:42
Type=AUTHENTICATION_ACCEPT
Process time:37
Attributes:
Acct-Interim-Interval=20
Service-Type=2
Framed-Protocol=1
Framed-IP-Address=83.234.37.196

10 14:23:42
Type=ACCOUNTING_REQUEST
Attributes:
User-Name=stepnoy
NAS-Identifier=amber.region19.ru
NAS-Port=5
Service-Type=2
Framed-Protocol=1
Framed-IP-Address=83.234.37.196
Acct-Status-Type=1
Acct-Session-Id=9949822-pppoe5
Acct-Authentic=1
Acct-Link-Count=1
Acct-Multi-Session-Id=9949822-pppoe5
NAS-Port-Type=5
Calling-Station-Id=008048495e5e

10 15:57:53
Type=ACCOUNTING_REQUEST
Attributes:
User-Name=stepnoy
NAS-Identifier=amber.region19.ru
NAS-Port=5
Service-Type=2
Framed-Protocol=1
Acct-Input-Octets=8287188
Framed-IP-Address=83.234.37.196
Acct-Output-Octets=72701169
Acct-Status-Type=2
Acct-Session-Time=7460
Acct-Input-Packets=67809
Acct-Session-Id=9949822-pppoe5
Acct-Authentic=1
Acct-Link-Count=1
Acct-Multi-Session-Id=9949822-pppoe5
Acct-Terminate-Cause=1
Acct-Output-Packets=83040
Acct-Output-Gigawords=0
Acct-Input-Gigawords=0
NAS-Port-Type=5
Calling-Station-Id=008048495e5e

По RADIUS все четко. Но вот в отображении.

Вернуться к началу

Администратор

Заголовок сообщения:

Добавлено: 05 фев 2008, 14:19

Разработчик

Зарегистрирован: 27 ноя 2006, 20:36
Сообщения: 5715
Карма: 93

Код:

10 14:16:07
Type=ACCOUNTING_REQUEST
Attributes:
User-Name=stepnoy
NAS-Identifier=amber.region19.ru
NAS-Port=27
Service-Type=2
Framed-Protocol=1
Framed-IP-Address=83.234.37.196
Acct-Status-Type=1
Acct-Session-Id=9949367-pppoe27
Acct-Authentic=1
Acct-Link-Count=1
Acct-Multi-Session-Id=9949367-pppoe27
NAS-Port-Type=5
Calling-Station-Id=008048495e5e

10 14:22:25
Type=ACCOUNTING_REQUEST
Attributes:
User-Name=stepnoy
NAS-Identifier=amber.region19.ru
NAS-Port=27
Service-Type=2
Framed-Protocol=1
Acct-Input-Octets=677185
Framed-IP-Address=83.234.37.196
Acct-Output-Octets=4886785
Acct-Status-Type=2
Acct-Session-Time=88085
Acct-Input-Packets=5451
Acct-Session-Id=9949367-pppoe27
Acct-Authentic=1
Acct-Link-Count=1
Acct-Multi-Session-Id=9949367-pppoe27
Acct-Terminate-Cause=1
Acct-Output-Packets=6427
Acct-Output-Gigawords=0
Acct-Input-Gigawords=0
NAS-Port-Type=5
Calling-Station-Id=008048495e5e

Посмотрите по временным меткам Start и Stop пакета получаем длительность сессии (14:22:25 - 14:16:07) = 6 мин. 18 сек. = 378 сек.
А в атрибуте идет:

Код:

Acct-Session-Time=88085

Может вам поставить опцию в конфигурации модуля:

Код:

ignore.acct.session.time=1

, тогда RADIUS будет игнорировать этот атрибут и сам считать длительность сессии.

Вернуться к началу

Заголовок сообщения:

Добавлено: 05 фев 2008, 14:42

Выставил, подождем результатов.

Вернуться к началу

Заголовок сообщения:

Добавлено: 06 фев 2008, 16:40

Так. Пока отодвинем эту проблему. Возникла другая.
NAS - mpd 3.18
Людей откидывает около 00:00. Выглядит со стороны BGRadius как отключение абонента самостоятельно. connection.log смотреть нет смысла. В логах RADIUS для каждой такой сессии есть одна отличительная особенность:
Acct-Terminate-Cause=10
По RFC это

Код:

NAS Request - NAS ended session for a non-error reason not otherwise listed here.

Возникает вопрос, что это с NAS.
В логах NAS все выглядит подозрительно:

Код:

Jan 24 23:58:06 nas mpd: [pptp014] RADIUS: RadiusAddServer Adding 192.168.0.110 
Jan 24 23:58:06 nas mpd: [pptp014] RADIUS: RadiusAccount: Sending accounting data (Type: 3) 
Jan 24 23:58:06 nas mpd: [pptp014] RADIUS: RadiusSendRequest: RAD_ACCOUNTING_RESPONSE for user yubil8_62 
Jan 24 23:58:26 nas mpd: [pptp014] RADIUS: RadiusAcctUpdate: Sending Accounting Update 
Jan 24 23:58:26 nas mpd: [pptp014] RADIUS: RadiusAccount for: yubil8_62 
Jan 24 23:58:26 nas mpd: [pptp014] RADIUS: RadiusAddServer Adding 192.168.0.110 
Jan 24 23:58:26 nas mpd: [pptp014] RADIUS: RadiusAccount: Sending accounting data (Type: 3) 
Jan 24 23:58:26 nas mpd: [pptp014] RADIUS: RadiusSendRequest: RAD_ACCOUNTING_RESPONSE for user yubil8_62 
Jan 24 23:58:46 nas mpd: [pptp014] RADIUS: RadiusAcctUpdate: Sending Accounting Update 
Jan 24 23:58:46 nas mpd: [pptp014] RADIUS: RadiusAccount for: yubil8_62 
Jan 24 23:58:46 nas mpd: [pptp014] RADIUS: RadiusAddServer Adding 192.168.0.110 
Jan 24 23:58:46 nas mpd: [pptp014] RADIUS: RadiusAccount: Sending accounting data (Type: 3) 
Jan 24 23:58:46 nas mpd: [pptp014] RADIUS: RadiusSendRequest: RAD_ACCOUNTING_RESPONSE for user yubil8_62 
Jan 24 23:59:06 nas mpd: [pptp014] RADIUS: RadiusAcctUpdate: Sending Accounting Update 
Jan 24 23:59:06 nas mpd: [pptp014] RADIUS: RadiusAccount for: yubil8_62 
Jan 24 23:59:06 nas mpd: [pptp014] RADIUS: RadiusAddServer Adding 192.168.0.110 
Jan 24 23:59:06 nas mpd: [pptp014] RADIUS: RadiusAccount: Sending accounting data (Type: 3) 
Jan 24 23:59:06 nas mpd: [pptp014] RADIUS: RadiusSendRequest: RAD_ACCOUNTING_RESPONSE for user yubil8_62 
Jan 24 23:59:26 nas mpd: [pptp014] RADIUS: RadiusAcctUpdate: Sending Accounting Update 
Jan 24 23:59:26 nas mpd: [pptp014] RADIUS: RadiusAccount for: yubil8_62 
Jan 24 23:59:26 nas mpd: [pptp014] RADIUS: RadiusAddServer Adding 192.168.0.110 
Jan 24 23:59:26 nas mpd: [pptp014] RADIUS: RadiusAccount: Sending accounting data (Type: 3) 
Jan 24 23:59:56 nas mpd: [pptp014] RADIUS: RadiusSendRequest: rad_send_request failed No valid RADIUS responses received 
--------------
Jan 25 00:00:57 nas mpd: pptp13: no reply to EchoRequest after 60 sec 
Jan 25 00:00:57 nas mpd: pptp13: killing connection with 192.168.5.56:2943 
Jan 25 00:00:57 nas mpd: pptp13-0: killing channel 
Jan 25 00:00:57 nas mpd: [pptp014] PPTP call terminated 
Jan 25 00:00:57 nas mpd: [pptp014] IFACE: Close event 
Jan 25 00:00:57 nas mpd: [pptp014] exec: /usr/local/etc/rc.d/downiface.sh ng14 inet yubil8_62 
Jan 25 00:00:57 nas mpd: [pptp014] exec: /sbin/route delete 83.234.37.8 -iface lo0 
Jan 25 00:00:57 nas mpd: [pptp014] exec: command returned 256 
Jan 25 00:00:57 nas mpd: [pptp014] exec: /sbin/ifconfig ng14 down delete -link0 
Jan 25 00:00:57 nas mpd: [pptp014] IPCP: Close event 
Jan 25 00:00:57 nas mpd: [pptp014] IPCP: state change Opened --> Closing 
Jan 25 00:00:57 nas mpd: [pptp014] IPCP: SendTerminateReq #236 
Jan 25 00:00:57 nas mpd: [pptp014] error writing len 8 frame to bypass: Network is down 
Jan 25 00:00:57 nas mpd: [pptp014] IPCP: LayerDown 
Jan 25 00:00:57 nas mpd: [pptp014] IFACE: Down event 
Jan 25 00:00:57 nas mpd: [pptp014] IFACE: Close event

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

Вернуться к началу

Администратор

Заголовок сообщения:

Добавлено: 06 фев 2008, 17:41

Разработчик

Зарегистрирован: 27 ноя 2006, 20:36
Сообщения: 5715
Карма: 93

Код:

Jan 25 00:00:57 nas mpd: pptp13: no reply to EchoRequest after 60 sec
Jan 25 00:00:57 nas mpd: pptp13: killing connection with 192.168.5.56:2943

Клиент не ответил на эхо пакет МПД. Возможная причина - у клиента стоит файрвол, который режет все входящие обращения. Ему нужно добавить ВПН сервер в список доверенных адресов.

Вернуться к началу

Заголовок сообщения:

Добавлено: 07 фев 2008, 08:04

В том и дело, что если бы что-то рубило пакеты, то рубило бы постоянно, т.к. всяко эхо-запросы идут не только в 00:00. Дело в смене времени, точнее, в счене суток. Пока не пойму куда копать, но понять очень хочется. В биллинге нет ничего, что связано со сменой суток, например, обрубание сессий или т.п., возможно какой-то атрибут передается на зпрос к NAS, а тот не отрабатывает или как-то не так отрабатывает.

Вернуться к началу

Заголовок сообщения:

Добавлено: 07 фев 2008, 12:50

Сегодня было замечено, что дропнуло около 7 клиентов, висящих на этом NAS, однако, не всех. С той же самой причиной. Становится уже интересно.

Вернуться к началу

Администратор

Заголовок сообщения:

Добавлено: 08 фев 2008, 12:13

Разработчик

Зарегистрирован: 27 ноя 2006, 20:36
Сообщения: 5715
Карма: 93

Все запросы на сброс биллинг логирует в connection.log. Для полной достоверности - вы можете запустить tcpdump с мониторингом 161 порта и поизучать запросы, шедшие от биллинга в проблемные моменты.

Вернуться к началу

Заголовок сообщения:

Добавлено: 18 мар 2008, 16:47

Опять назрело

mp 3.18, BGBilling 4.3. Кстати, имеет смысл ставить mpd4\5? Рекомендуете? Вот мой конф с VPN-сервера:

Код:

default:
        load client0
        load client1
        load client2
        load client3
        load client4
        load client5
        load client6
---------------------
client60:
        new -i ng60 pptp060 pptp060
        load client_standard

client_standard:
        set ipcp ranges VPN_SERVER_IP CLIENTS_RANGE
        set pptp enable incoming
        set pptp disable originate
        set iface disable on-demand
        set iface enable proxy-arp
        set iface idle 2400
        set iface enable tcpmssfix
        set bundle enable multilink
        set link no acfcomp protocomp
        set iface up-script /usr/local/etc/rc.d/upiface.sh
        set iface down-script /usr/local/etc/rc.d/downiface.sh
        set link no pap chap
        set link no chap-msv1
        set link enable chap-msv2
        set link mtu 1360
        set link mru 1360
        set link keep-alive 60 180
        set ipcp no vjcomp
        set ipcp dns DNS
        set bundle no compression
        set ccp no mppc
        set ccp no mpp-e40
        set ccp no mpp-e128
        set ccp no mpp-stateless
# RADIUS
        set radius retries 3
        set radius timeout 10
        set radius server 192.168.0.110 secret 1812 1813
        set radius acct-update 5
        set radius me 192.168.0.110
        set ipcp enable radius-ip
        set bundle enable radius-acct
        set bundle enable radius-auth
        set radius update-limit-in 100000
        set radius update-limit-out 100000

Подскажите, оно верное, что поправить? Я ваш конф глядел, но там для mpd4\5 скорее всего. Требуется помощь, т.к. уже отрубает частенько. И вот эта ошибка прет тоже постоянно:

Код:

RadiusSendRequest: rad_send_request failed No valid RADIUS responses received

Последний раз редактировалось S 24 мар 2008, 12:46, всего редактировалось 1 раз.

Вернуться к началу

Администратор

Заголовок сообщения:

Добавлено: 18 мар 2008, 16:51

Разработчик

Зарегистрирован: 27 ноя 2006, 20:36
Сообщения: 5715
Карма: 93

А что назрело? В чем проблема?

Вернуться к началу

Заголовок сообщения:

Добавлено: 18 мар 2008, 16:59

Отключение абонентов либо в 00:00, либо в 12:00, либо вообще просто по причине в логах радиуса:

Код:

Acct-Terminate-Cause=10

Настораживает стабильность такого отключения. То есть, может разом скинуть человек 10. У меня два NAS, один РРРоЕ, другой VPN. Стал замечать сперва что в 00:00 (+\- несколько минут) отбрасывает скопом, но не всех, а выборочно. Не могу найти между ними связь, но в логах выдает, что не было ответа радиуса, дропаем значит. По поводу конфа - он не вызывает подозрений?

Вернуться к началу

Администратор

Заголовок сообщения:

Добавлено: 19 мар 2008, 13:21

Разработчик

Зарегистрирован: 27 ноя 2006, 20:36
Сообщения: 5715
Карма: 93

Попробуйте перейти на мпд4.

Цитата:

RadiusSendRequest: rad_send_request failed No valid RADIUS responses received

- эта ошибка не должна сбрасывать, как я понимаю, не был получен ответ авторизации от радиуса вовремя.
Посмотрите connection.log по сброшенным соединениям (можете выбрать с помощью grep), есть ли сигналы на сброс от биллинга.

Вернуться к началу

Заголовок сообщения:

Добавлено: 24 мар 2008, 12:44

Я конечно же буду пересаживаться на mpd4, но пока что проблемы по отключению продолжаются. Сегодня такая картина (сделал grep "has stop Packet => true"):

Код:

INFO   24.03.2008 12:13:29  [ LS-00844; evroset; 38123 ] DialUpNASConnection has stop Packet => true
INFO   24.03.2008 12:13:29  [ LS-01110; riteil; 49030 ] DialUpNASConnection has stop Packet => true
INFO   24.03.2008 12:13:29  [ LS-01004; energosbit_abakan; 24784 ] DialUpNASConnection has stop Packet => true
INFO   24.03.2008 12:13:29  [ LS-00912; rgs_sibir_2; 29577 ] DialUpNASConnection has stop Packet => true
INFO   24.03.2008 12:13:29  [ LS-00859; energo; 91332 ] DialUpNASConnection has stop Packet => true
INFO   24.03.2008 12:13:29  [ LS-00867; mongol; 94783 ] DialUpNASConnection has stop Packet => true
INFO   24.03.2008 12:13:29  [ LS-00850; sibnedra; 81853 ] DialUpNASConnection has stop Packet => true
INFO   24.03.2008 12:13:29  [ LS-00866; apteka2; 62894 ] DialUpNASConnection has stop Packet => true
INFO   24.03.2008 12:13:29  [ LS-00081; chap51_65; 95304 ] DialUpNASConnection has stop Packet => true
INFO   24.03.2008 12:13:29  [ LS-01127; htk; 78695 ] DialUpNASConnection has stop Packet => true
INFO   24.03.2008 12:13:29  [ LS-00652; sov78_33; 47535 ] DialUpNASConnection has stop Packet => true
INFO   24.03.2008 12:13:29  [ LS-00873; stekloplast; 86522 ] DialUpNASConnection has stop Packet => true
INFO   24.03.2008 12:13:30  [ LS-00346; kosmo19a_102; 57396 ] DialUpNASConnection has stop Packet => true
INFO   24.03.2008 12:13:30  [ LS-00212; gork2_109; 44800 ] DialUpNASConnection has stop Packet => true
INFO   24.03.2008 12:13:30  [ LS-00287; sov90_82; 87977 ] DialUpNASConnection has stop Packet => true
INFO   24.03.2008 12:13:30  [ CD-06/049/2 ; apteka3; 99133 ] DialUpNASConnection has stop Packet => true
INFO   24.03.2008 12:13:30  [ LS-00445; sov98_46; 5324 ] DialUpNASConnection has stop Packet => true
INFO   24.03.2008 12:13:30  [ LS-01020 ; sov79_2; 45282 ] DialUpNASConnection has stop Packet => true
INFO   24.03.2008 12:13:30  [ LS-00042; haustova; 90406 ] DialUpNASConnection has stop Packet => true
INFO   24.03.2008 12:13:30  [ LS-01088 ; kalin28_6; 91772 ] DialUpNASConnection has stop Packet => true
INFO   24.03.2008 12:13:30  [ LS-00335; gork1_60; 70644 ] DialUpNASConnection has stop Packet => true
INFO   24.03.2008 12:13:30  [ LS-00457; kalin30_57; 73735 ] DialUpNASConnection has stop Packet => true
INFO   24.03.2008 12:13:30  [ LS-00233; yubil5_67; 8158 ] DialUpNASConnection has stop Packet => true

Не всех выкинуло разом, а только часть, у каждого абонента (специально проверил) причина выглядит так:

Код:

INFO   24.03.2008 12:13:29  [ LS-00912; rgs_sibir_2; 29577 ] DialUpNASConnection stoppingConnection
INFO   24.03.2008 12:13:29  [ LS-00912; rgs_sibir_2; 29577 ] DialUpNASConnection has stop Packet => true
INFO   24.03.2008 12:13:29  [ LS-00912; rgs_sibir_2; 29577 ] DialUpNASConnection set STATUS=3
INFO   24.03.2008 12:13:29  [ LS-00912; rgs_sibir_2; 29577 ] DialUpNASConnection sessionTime => 237579

Просто понять не могу, чего происходит.
В mpd.stat выглядит тоже массовое отключение:

Код:

Mon Mar 24 12:15:28 KRAT 2008 kalin30_57 close connection on ng4
Mon Mar 24 12:15:28 KRAT 2008 sov79_2 close connection on ng8
Mon Mar 24 12:15:28 KRAT 2008 sov98_46 close connection on ng15
Mon Mar 24 12:15:28 KRAT 2008 gork2_109 close connection on ng29
Mon Mar 24 12:15:28 KRAT 2008 haustova close connection on ng30
Mon Mar 24 12:15:28 KRAT 2008 gork1_60 close connection on ng20
Mon Mar 24 12:15:29 KRAT 2008 kalin28_6 close connection on ng31
Mon Mar 24 12:15:29 KRAT 2008 energo close connection on ng3
Mon Mar 24 12:15:29 KRAT 2008 htk close connection on ng23
Mon Mar 24 12:15:29 KRAT 2008 kosmo19a_102 close connection on ng27
Mon Mar 24 12:15:29 KRAT 2008 chap51_65 close connection on ng21
Mon Mar 24 12:15:29 KRAT 2008 apteka2 close connection on ng9
Mon Mar 24 12:15:29 KRAT 2008 sibnedra close connection on ng10
Mon Mar 24 12:15:29 KRAT 2008 stekloplast close connection on ng25
Mon Mar 24 12:15:29 KRAT 2008 sov78_33 close connection on ng6
Mon Mar 24 12:15:29 KRAT 2008 sov90_82 close connection on ng14
Mon Mar 24 12:15:29 KRAT 2008 mongol close connection on ng7
Mon Mar 24 12:15:29 KRAT 2008 apteka3 close connection on ng5
Mon Mar 24 12:16:24 KRAT 2008 yubil5_67 close connection on ng16

У всех в NAS одно и тоже:

Код:

Mar 24 12:15:28 nas mpd: pptp28: no reply to EchoRequest after 60 sec
Mar 24 12:15:28 nas mpd: pptp28: killing connection with 192.168.4.10:1244
Mar 24 12:15:28 nas mpd: pptp28-0: killing channel
Mar 24 12:15:28 nas mpd: [pptp030] PPTP call terminated
Mar 24 12:15:28 nas mpd: [pptp030] IFACE: Close event
Mar 24 12:15:28 nas mpd: [pptp030] exec: /usr/local/etc/rc.d/downiface.sh ng30 inet haustova
Mar 24 12:15:28 nas mpd: [pptp030] exec: /sbin/route delete хх.хх.хх.хх -iface lo0
Mar 24 12:15:28 nas mpd: [pptp030] exec: command returned 256
Mar 24 12:15:28 nas mpd: [pptp030] exec: /sbin/ifconfig ng30 down delete -link0
Mar 24 12:15:28 nas mpd: [pptp030] IPCP: Close event
Mar 24 12:15:28 nas mpd: [pptp030] IPCP: state change Opened --> Closing
Mar 24 12:15:28 nas mpd: [pptp030] IPCP: SendTerminateReq #141
Mar 24 12:15:28 nas mpd: [pptp030] error writing len 8 frame to bypass: Network is down
Mar 24 12:15:28 nas mpd: [pptp030] IPCP: LayerDown
Mar 24 12:15:28 nas mpd: [pptp030] IFACE: Down event
Mar 24 12:15:28 nas mpd: [pptp030] IFACE: Close event

Это происходит на двух NAS - оба VPN-сервера. Может что в конфе не так, т.к. я делал второй нас, копируя просто конф.

Вернуться к началу

Администратор

Заголовок сообщения:

Добавлено: 24 мар 2008, 12:59

Разработчик

Зарегистрирован: 27 ноя 2006, 20:36
Сообщения: 5715
Карма: 93

Цитата:

Mar 24 12:15:28 nas mpd: pptp28: no reply to EchoRequest after 60 sec

По-моему, MPD рвет соединения из-за неответа на эхо-пакет. Биллинг их не сбрасывает..

Цитата:

INFO 24.03.2008 12:13:29 [ LS-00844; evroset; 38123 ] DialUpNASConnection has stop Packet => true

Это корректное сообщение, оначает что пришел стоп-пакет и соединение закрывается. Вы лучше выберите grep 38123, например, чтобы получить лог по одному соединению.

Вернуться к началу

Заголовок сообщения:

Добавлено: 24 мар 2008, 13:05

Вот именно. А почему он их рвет, а другие нет? Посмотрите выше конф, может там чего? Сокеты проверил, вроде нормально. Просто скажите, мож в конфе что не корректно, а так - буду рыть в mpd.

Вернуться к началу

Администратор

Заголовок сообщения:

Добавлено: 24 мар 2008, 13:38

Разработчик

Зарегистрирован: 27 ноя 2006, 20:36
Сообщения: 5715
Карма: 93

У этих клиентов файрволы не стоят?

Вернуться к началу

Заголовок сообщения:

Добавлено: 24 мар 2008, 13:58

Хороший вопрос. Не думаю, что у всех так. Я попробую сам клиентом выступить, проверить, завтра например. Может быть и такая ситуация. Но почему, допустим, во-первых рубит сразу много и в одно время? В другое время отключение выглядит более-менее плавно, нет таких скачков. Буду дальше наблюдать.

Вернуться к началу

Страница 1 из 1

[ Сообщений: 28 ]

Список форумов » BGBilling » Модули Интернета » Модуль DialUp (VPN)

Часовой пояс: UTC + 5 часов [ Летнее время ]

Кто сейчас на конференции

Сейчас этот форум просматривают: нет зарегистрированных пользователей и гости: 1

Вы не можете начинать темы
Вы не можете отвечать на сообщения
Вы не можете редактировать свои сообщения
Вы не можете удалять свои сообщения
Вы не можете добавлять вложения

Перейти:

BiTel

Проблемы какие-то, навалились прям :)

Кто сейчас на конференции