Народ помогите разобраться. Настроил циску, в утм завел карточки. При авторизации радиус говорит такое:
?Debug : Apr 14 15:08:12 AuthServer: User <9527> connecting
?Debug : Apr 14 15:08:12 AuthServer: Session for sessionid <9527> not found in <10.10.1.2> cache
ERROR : Apr 14 15:08:12 RADIUS DBA: Can't find login <9527>
?Debug : Apr 14 15:08:12 RADIUS DBA: Searching card login <000009527>
ERROR : Apr 14 15:08:12 RADIUS DBA: Can't find card login <000009527>
?Debug : Apr 14 15:08:12 AuthServer: Attempt to add new Card user: <9527>
?Debug : Apr 14 15:08:12 AuthServer: Skiping non-digit symbols
?Debug : Apr 14 15:08:12 RADIUS DBA: Sending Auto-Add Request for Card-ID: 9527
?Debug : Apr 14 15:08:13 RADIUS Stream[plugin]: Account <2> with balance <100.000>
?Debug : Apr 14 15:08:13 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Apr 14 15:08:13 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Apr 14 15:08:13 RADIUS Stream[plugin]: TelLink: SLID/SID/AID: 2/5/2; Count: 1 Num <84173862> Login <84173862>
?Debug : Apr 14 15:08:13 RADIUS DBA: Adding tel login <84173862> into storage
?Debug : Apr 14 15:08:13 RADIUS Stream[plugin]: Got User-Autoadd id <2>
?Debug : Apr 14 15:08:13 AuthServer: Got AutoAdd 2 UID from core.
Info : Apr 14 15:08:14 AuthServer: Retry:0 to find user <9527>
ERROR : Apr 14 15:08:14 RADIUS DBA: Can't find login <9527>
?Debug : Apr 14 15:08:14 RADIUS DBA: Searching card login <000009527>
ERROR : Apr 14 15:08:14 RADIUS DBA: Can't find card login <000009527>
Info : Apr 14 15:08:15 AuthServer: Retry:1 to find user <9527>
ERROR : Apr 14 15:08:15 RADIUS DBA: Can't find login <9527>
?Debug : Apr 14 15:08:15 RADIUS DBA: Searching card login <000009527>
ERROR : Apr 14 15:08:15 RADIUS DBA: Can't find card login <000009527>
Info : Apr 14 15:08:16 AuthServer: Retry:2 to find user <9527>
ERROR : Apr 14 15:08:16 RADIUS DBA: Can't find login <9527>
?Debug : Apr 14 15:08:16 RADIUS DBA: Searching card login <000009527>
ERROR : Apr 14 15:08:16 RADIUS DBA: Can't find card login <000009527>
Warn : Apr 14 15:08:16 AuthServer: Errors adding card <9527>. Rehash failed
ERROR : Apr 14 15:08:16 AuthServer: No data for User <9527> found.
?Debug : Apr 14 15:08:16 AuthServer: Auth reply: RPacket:
Code: 3; ID: 160
<Vendor: 0; Attr: 18>[21]: 417574686f72697a6174696f6e206661696c65642e
<Vendor: 9; Attr: 103>[19]: 683332332d72657475726e2d636f64653d2d31
?Debug : Apr 14 15:08:16 RADIUS Packet: raw data constructed! size <70>
?Debug : Apr 14 15:08:16 RadiusSocket: Moving RADIUS packet into send queue
?Debug : Apr 14 15:08:16 RadiusSocket: RADIUS raw data sent
?Debug : Apr 14 15:08:16 AuthServer: Next...
?Trace : Apr 14 15:08:16 AuthServer: Process loop step
?Debug : Apr 14 15:08:16 RadiusSocket: Waiting for RADIUS raw data
?Debug : Apr 14 15:08:23 RadiusSocket: RADIUS packet successfully received
?Debug : Apr 14 15:08:23 RadiusSocket: RADIUS raw data obtained
?Debug : Apr 14 15:08:23 RADIUS Packet: Size <1218>; HDR.Size <1218>
?Debug : Apr 14 15:08:23 AcctServer: Recv...
?Debug : Apr 14 15:08:23 AcctServer: Packet from <10.10.1.2> packet dump: RPacke
При этом заводит такого карточного пользователя, а не авторизует почему то. Может подскажете куда копать добрые люди
Телефония
-
orachimary
- Сообщения: 41
- Зарегистрирован: Ср ноя 12, 2008 13:12
?Debug : Apr 15 11:26:00 AuthServer: User <5290> connecting
?Debug : Apr 15 11:26:00 AuthServer: Session for sessionid <5290> not found in <10.10.1.2> cache
?Debug : Apr 15 11:26:00 RADIUS DBA: Info for login <5290> found. type <3>
?Debug : Apr 15 11:26:00 RADIUS DBA: Password found for tel login:5290
?Debug : Apr 15 11:26:00 AuthServer: Auth scheme: PAP
?Debug : Apr 15 11:26:00 AuthServer: PAP: <6657> vs <6657>
?Debug : Apr 15 11:26:00 AuthServer: PAP: Authorized user <5290>
?Debug : Apr 15 11:26:00 AuthServer: Tel session limit:2 session count:0 for user:5290
?Debug : Apr 15 11:26:00 AuthServer: Calculated maximum session time: 0 zoneid: 0 dir id: 0
?Debug : Apr 15 11:26:00 AuthServer: Zero session time
?Debug : Apr 15 11:26:00 AuthServer: Calling fill radius attributes for NAS. Attr storage size <0>
Notice: Apr 15 11:26:00 AuthServer: Login incorrect <5290> from NAS <10.10.1.2> CLID <-> Calling-station <3532949539>
Notice: Apr 15 11:26:00 AuthServer: Authorization failed for user <5290>
?Debug : Apr 15 11:26:00 AuthServer: Auth reply: RPacket:
Code: 3; ID: 52
<Vendor: 0; Attr: 18>[21]: 417574686f72697a6174696f6e206661696c65642e
<Vendor: 9; Attr: 103>[19]: 683332332d72657475726e2d636f64653d2d35
?Debug : Apr 15 11:26:00 RADIUS Packet: raw data constructed! size <70>
?Debug : Apr 15 11:26:00 RadiusSocket: Moving RADIUS packet into send queue
?Debug : Apr 15 11:26:00 RadiusSocket: RADIUS raw data sent
?Debug : Apr 15 11:26:00 AuthServer: Next...
?Trace : Apr 15 11:26:00 AuthServer: Process loop step
?Debug : Apr 15 11:26:00 RadiusSocket: Waiting for RADIUS raw data
?Debug : Apr 15 11:26:03 RADIUS Stream[plugin]: Ping reply received
Что может быть? Логин уже находит. Люди ХеЛП!!!
?Debug : Apr 15 11:26:00 AuthServer: Session for sessionid <5290> not found in <10.10.1.2> cache
?Debug : Apr 15 11:26:00 RADIUS DBA: Info for login <5290> found. type <3>
?Debug : Apr 15 11:26:00 RADIUS DBA: Password found for tel login:5290
?Debug : Apr 15 11:26:00 AuthServer: Auth scheme: PAP
?Debug : Apr 15 11:26:00 AuthServer: PAP: <6657> vs <6657>
?Debug : Apr 15 11:26:00 AuthServer: PAP: Authorized user <5290>
?Debug : Apr 15 11:26:00 AuthServer: Tel session limit:2 session count:0 for user:5290
?Debug : Apr 15 11:26:00 AuthServer: Calculated maximum session time: 0 zoneid: 0 dir id: 0
?Debug : Apr 15 11:26:00 AuthServer: Zero session time
?Debug : Apr 15 11:26:00 AuthServer: Calling fill radius attributes for NAS. Attr storage size <0>
Notice: Apr 15 11:26:00 AuthServer: Login incorrect <5290> from NAS <10.10.1.2> CLID <-> Calling-station <3532949539>
Notice: Apr 15 11:26:00 AuthServer: Authorization failed for user <5290>
?Debug : Apr 15 11:26:00 AuthServer: Auth reply: RPacket:
Code: 3; ID: 52
<Vendor: 0; Attr: 18>[21]: 417574686f72697a6174696f6e206661696c65642e
<Vendor: 9; Attr: 103>[19]: 683332332d72657475726e2d636f64653d2d35
?Debug : Apr 15 11:26:00 RADIUS Packet: raw data constructed! size <70>
?Debug : Apr 15 11:26:00 RadiusSocket: Moving RADIUS packet into send queue
?Debug : Apr 15 11:26:00 RadiusSocket: RADIUS raw data sent
?Debug : Apr 15 11:26:00 AuthServer: Next...
?Trace : Apr 15 11:26:00 AuthServer: Process loop step
?Debug : Apr 15 11:26:00 RadiusSocket: Waiting for RADIUS raw data
?Debug : Apr 15 11:26:03 RADIUS Stream[plugin]: Ping reply received
Что может быть? Логин уже находит. Люди ХеЛП!!!
-
-=Master=-
- Сообщения: 5
- Зарегистрирован: Вт апр 28, 2009 11:54
Телефония
Продублирую...у меня таже проблема, телефония работает у кого-нибудь? 
Что является пин-кодом, при карточной телефонии?
Что является пин-кодом, при карточной телефонии?
-
orachimary
- Сообщения: 41
- Зарегистрирован: Ср ноя 12, 2008 13:12
-
-=Master=-
- Сообщения: 5
- Зарегистрирован: Вт апр 28, 2009 11:54
Телефония
свежий лог, может быть кто-нибудь выскажет хоть какие-то идеи?
?Debug : Apr 30 15:06:26 AuthServer: User <6032> connecting
?Debug : Apr 30 15:06:26 AuthServer: Session for sessionid <6032> not found in <10.0.3.179> cache
ERROR : Apr 30 15:06:26 RADIUS DBA: Can't find login <6032>
?Debug : Apr 30 15:06:26 RADIUS DBA: Searching card login <000006032>
ERROR : Apr 30 15:06:26 RADIUS DBA: Can't find card login <000006032>
?Debug : Apr 30 15:06:26 AuthServer: Attempt to add new Card user: <6032>
?Debug : Apr 30 15:06:26 AuthServer: Card Auto-add is disabled
ERROR : Apr 30 15:06:26 AuthServer: No data for User <6032> found.
?Debug : Apr 30 15:06:26 AuthServer: Auth reply: RPacket:
Code: 3; ID: 253
<Vendor: 0; Attr: 18>[21]: 417574686f72697a6174696f6e206661696c65642e
<Vendor: 9; Attr: 103>[19]: 683332332d72657475726e2d636f64653d2d31
?Debug : Apr 30 15:06:26 AuthServer: User <6032> connecting
?Debug : Apr 30 15:06:26 AuthServer: Session for sessionid <6032> not found in <10.0.3.179> cache
ERROR : Apr 30 15:06:26 RADIUS DBA: Can't find login <6032>
?Debug : Apr 30 15:06:26 RADIUS DBA: Searching card login <000006032>
ERROR : Apr 30 15:06:26 RADIUS DBA: Can't find card login <000006032>
?Debug : Apr 30 15:06:26 AuthServer: Attempt to add new Card user: <6032>
?Debug : Apr 30 15:06:26 AuthServer: Card Auto-add is disabled
ERROR : Apr 30 15:06:26 AuthServer: No data for User <6032> found.
?Debug : Apr 30 15:06:26 AuthServer: Auth reply: RPacket:
Code: 3; ID: 253
<Vendor: 0; Attr: 18>[21]: 417574686f72697a6174696f6e206661696c65642e
<Vendor: 9; Attr: 103>[19]: 683332332d72657475726e2d636f64653d2d31
-
mobilesfinks
- Сообщения: 14
- Зарегистрирован: Пт ноя 13, 2009 13:56
Вопрос такой же. Настраиваю систему с нуля, и в первый раз. Вот наткнулся на такие грабли. Добавлял, пользователя и в обычные и в системные. Всё равно в логах Радиус сервера
в итоге шлюз зарегится на ГК не могёт.
Код: Выделить всё
?Debug : Nov 14 22:25:28 AuthServer: User <cisco> connecting
?Debug : Nov 14 22:25:28 AuthServer: Session for sessionid <cisco> not found in <127.0.0.1> cache
ERROR : Nov 14 22:25:28 RADIUS DBA: Can't find login <cisco>
ERROR : Nov 14 22:25:28 RADIUS DBA: Card login <cisco> contains not digit symbol with code <99> ! Can't find card login
?Debug : Nov 14 22:25:28 AuthServer: Attempt to add new Card user: <cisco>
?Debug : Nov 14 22:25:28 RADIUS DBA: Sending Auto-Add Request for Card-ID: cisco
?Debug : Nov 14 22:25:28 RADIUS Stream[plugin]: Got User-Autoadd id <-13>
?Debug : Nov 14 22:25:28 StreamConnection: Message id <0x202d>, handler returns 0
?Debug : Nov 14 22:25:28 AuthServer: Got AutoAdd -13 UID from core.
ERROR : Nov 14 22:25:28 AuthServer: No data for User <cisco> found.
?Debug : Nov 14 22:25:28 AuthServer: Auth reply: RPacket:
Code: 3; ID: 138
-
mobilesfinks
- Сообщения: 14
- Зарегистрирован: Пт ноя 13, 2009 13:56
-
mobilesfinks
- Сообщения: 14
- Зарегистрирован: Пт ноя 13, 2009 13:56
кто знает подскажите пожалуйста.
Завёл пользователя. шлюз на гейткипере зарегился.
Дальше при звонке на шлюз и вводе любого пина выдаётся голосовое сообщение "Система перегружена". Пробовал и неактивированную карту, и активированную через веб морду.
Может неправильно создан пользователь для регистрации Шлюза? Какой тип услуги на него надо вешать? Надо ли вообще? Этот момент в мануале к УТМ вообще не окучен никак.
Да ещё, после набора номера, на радиус сервер ничего не отправляется. Возможно ли что некорректно настроен dial-peer на шлюзе?
Вот настройки моих диал пиров.
Ещё заметил такой момент. В мануале по настройке системы карточной телефонии указано, что uid-len=4, а pid-len=6 - в биллинге же минимальная длина пароля карточки 8 цифр. Насколько я понял мне нужно pid-len делать равным 8.
И ещё очень интересный момент - НУЖНО ЛИ в конфиге шлюза указывать адрес RADIUS сервера? В мануале указаны лишь VSA атрибуты, но не адрес сервера.
Завёл пользователя. шлюз на гейткипере зарегился.
Дальше при звонке на шлюз и вводе любого пина выдаётся голосовое сообщение "Система перегружена". Пробовал и неактивированную карту, и активированную через веб морду.
Может неправильно создан пользователь для регистрации Шлюза? Какой тип услуги на него надо вешать? Надо ли вообще? Этот момент в мануале к УТМ вообще не окучен никак.
Да ещё, после набора номера, на радиус сервер ничего не отправляется. Возможно ли что некорректно настроен dial-peer на шлюзе?
Вот настройки моих диал пиров.
Код: Выделить всё
dial-peer voice 2 voip
destination-pattern .T
voice-class codec 1
session target ipv4:192.168.254.1
!
dial-peer voice 1 pots
application debit
incoming called-number T
direct-inward-dial
port 0:D
forward-digits 0
prefix 96
!
Код: Выделить всё
call application voice debit tftp://192.168.254.1/app_debitcard.2.0.2.3_ru.tcl
call application voice debit uid-len 4
call application voice debit pin-len 6
call application voice debit language 0 ru
call application voice debit set-location ru 0 tftp://192.168.254.1/prompts/ru/
-
mobilesfinks
- Сообщения: 14
- Зарегистрирован: Пт ноя 13, 2009 13:56
Продвинулся немного дальше, теперь практически вникнул в биллинг. Настроил правильно, я думаю.
разобрался практически со всем, теперь вот только одна закавыка. Когда приходит звонок на шлюз, срабатывает IVR, я ввожу пин и мне в ответ "извините система перегружена".
в логах Циски видим такие строки:
На гейт кипере циска зарегилась, а вот дальше косяк какой то, чёт ей не нравится. Может кто подскажет где копать? Если нужно отвечу более подробно.
По поводу лога:
Я вижу что написано, и читать по английски умею, но при регистрации на Гейткипере циска регится по RadAlias, а вот потом по RadAcc даже не хочет. В логах Радиуса пусто, в логах ГК пусто. Где смотреть не знаю просто.
Вот мой конфиг циски AS5300:
что ещё показать?
разобрался практически со всем, теперь вот только одна закавыка. Когда приходит звонок на шлюз, срабатывает IVR, я ввожу пин и мне в ответ "извините система перегружена".
в логах Циски видим такие строки:
Код: Выделить всё
Nov 18 22:24:23.521: %AAA-3-BADSERVERTYPEERROR: Cannot process accounting server type radius (UNKNOWN)
Nov 18 22:24:24.161: %ISDN-6-CONNECT: Interface Serial0:7 is now connected to 74012 N/A
Nov 18 22:24:42.854: %ISDN-6-DISCONNECT: Interface Serial0:7 disconnected from 74012 , call lasted 18 seconds
По поводу лога:
Я вижу что написано, и читать по английски умею, но при регистрации на Гейткипере циска регится по RadAlias, а вот потом по RadAcc даже не хочет. В логах Радиуса пусто, в логах ГК пусто. Где смотреть не знаю просто.
Вот мой конфиг циски AS5300:
Код: Выделить всё
sh run
Current configuration : 2839 bytes
!
! No configuration change since last restart
!
version 12.3
service timestamps debug datetime msec
service timestamps log datetime msec
no service password-encryption
!
hostname Router
!
boot-start-marker
boot-end-marker
!
no logging console
enable secret 5 $1$afr.ljk,j`,
!
!
!
resource-pool disable
clock timezone EET 2
!
aaa new-model
!
!
aaa authentication login h323 group radius
aaa authorization exec h323 group radius
aaa accounting connection h323 start-stop group radius
aaa session-id common
ip subnet-zero
no ip domain lookup
!
!
isdn switch-type primary-net5
!
!
voice service voip
!
voice class codec 1
codec preference 1 g729r8
codec preference 2 g711ulaw
codec preference 3 g723r63
!
!
!
!
!
!
!
!
!
username user secret 5 $1$1afr.ljk,j`,!
!
controller E1 0
pri-group timeslots 1-31
!
controller E1 1
clock source line secondary 1
!
controller E1 2
clock source line secondary 2
!
controller E1 3
clock source line secondary 3
!
gw-accounting aaa
acct-template callhistory-detail
!
!
!
interface Ethernet0
no ip address
shutdown
!
interface Serial0
no ip address
shutdown
clock rate 2015232
no fair-queue
!
interface Serial1
no ip address
shutdown
clock rate 2015232
no fair-queue
!
interface Serial2
no ip address
shutdown
clock rate 2015232
no fair-queue
!
interface Serial3
no ip address
shutdown
clock rate 2015232
no fair-queue
!
interface Serial0:15
description AS5300 <--E1--> ATC M-200
no ip address
encapsulation hdlc
isdn switch-type primary-net5
isdn incoming-voice modem
isdn map address .* plan isdn type unknown
isdn T310 50000
isdn bchan-number-order ascending
isdn sending-complete
isdn outgoing-voice info-transfer-capability 3.1kHz-audio
no fair-queue
no cdp enable
!
interface FastEthernet0
ip address 192.168.254.2 255.255.255.0
no ip route-cache
no ip mroute-cache
duplex auto
speed auto
keepalive 60
h323-gateway voip interface
h323-gateway voip id localhost ipaddr 192.168.254.1 1718
h323-gateway voip h323-id cisco
!
ip classless
no ip http server
!
!
access-list 2 permit 192.168.254.1
!
!
!
radius-server vsa send accounting
radius-server vsa send authentication
!
call application voice debit tftp://192.168.254.1/app_debitcard.2.0.2.3_ru.tcl
call application voice debit uid-len 4
call application voice debit pin-len 8
call application voice debit language 0 ru
call application voice debit set-location ru 0 tftp://192.168.254.1/prompts/ru/
!
voice-port 0:D
cptone RU
!
!
!
dial-peer voice 2 voip
destination-pattern .T
voice-class codec 1
session target ras
!
dial-peer voice 1 pots
application debit
incoming called-number T
direct-inward-dial
port 0:D
forward-digits 0
prefix 96
!
gateway
!
!
line con 0
line aux 0
line vty 0 4
!
ntp clock-period 17180401
ntp server 192.168.254.1 prefer
end
-
mobilesfinks
- Сообщения: 14
- Зарегистрирован: Пт ноя 13, 2009 13:56
С предыдущим разобрался.
Нужно было указать циске адрес Радиус сервера.
Дальше возникла следующая заморочка:
Дозвонился, ввожу пинкод карты, мне отвечает, что пинкод неправильный. Лезу в админку, смотрю что карта добавилась. Смотрю в её свойствах - нет услуги.
Создал фиктивную услугу, скопировал в неё цены с основной. Поставил галочку "добавлять по умолчанию". В базовой услуге эта галочка не активна.
При вводе пинкода уже другой карты, она добавилась, услуга завелась, но в ответ всё же пишет, что "неправильно введен пинкод.
Да ещё карты при автодобавлени (автоактивации) в списке красными нарисованы, если изменить в них параметр "Интернет" на "включен", то карточные пользователи становятся зелеными. Тем не менее на результат ввода пинкода это не влияет.
Вот что нашёл Debug.log
А вот что сыпется в radius.log
т.е. в логе радиуса видно, что карточку № 0003 не видит в БД
про других пользователей:
для регистрации шлюза заведены 2 пользователя
1 - cisco - для регистрации его на ГейтКипере
2 - 74012 - для регистрации при звонке - иначе сыпятся ошибки, мол неизвестный логин/пароль в логах
Им обоим добавлена услуга телефонии.
Возможно у меня где то в этом косяк, но понять пока не могу. Может кто сможет подсказать более точно?
Нужно было указать циске адрес Радиус сервера.
Дальше возникла следующая заморочка:
Дозвонился, ввожу пинкод карты, мне отвечает, что пинкод неправильный. Лезу в админку, смотрю что карта добавилась. Смотрю в её свойствах - нет услуги.
Создал фиктивную услугу, скопировал в неё цены с основной. Поставил галочку "добавлять по умолчанию". В базовой услуге эта галочка не активна.
При вводе пинкода уже другой карты, она добавилась, услуга завелась, но в ответ всё же пишет, что "неправильно введен пинкод.
Да ещё карты при автодобавлени (автоактивации) в списке красными нарисованы, если изменить в них параметр "Интернет" на "включен", то карточные пользователи становятся зелеными. Тем не менее на результат ввода пинкода это не влияет.
Вот что нашёл Debug.log
Код: Выделить всё
?Debug : Nov 19 12:03:36 Radius: init_session_log id <2>
?Debug : Nov 19 12:03:36 DBCtx: <679506944> SQL query: INSERT INTO tel_sessions_log(account_id,slink_id,recv_date,last_update_date, NAS_Port,Acct_Delay_Time, Acct_Session_Id,NAS_Port_Type,User_Name,Service_Type,Framed_Protocol,NAS_IP_Address,NAS_Id,Acct_Status_Type, Acct_Input_Packets,Acct_Input_Octets,Acct_Input_Gigawords,Acct_Output_Packets,Acct_Output_Octets,Acct_Output_Gigawords, Acct_Session_Time,Acct_Terminate_Cause,Called_Station_Id,Calling_Station_Id,h323_remote_address,h323_conf_id, h323_setup_time,h323_call_origin, h323_call_type,h323_connect_time,h323_disconnect_time,h323_disconnect_cause, h323_gw_id,zone_id,did,session_start_date) VALUES('3','3','1258625016','1258625016','0','0','00000042','0','74012','1','0','50243776','192.168.254.2','1','0','0','0','0','0','0','0','0','570235','74012','','h323-conf-id=A348F4B4 D42911DE 803BAE22 418E4AC0','h323-setup-time=12\:03\:36.592 EET Thu Nov 19 2009','h323-call-origin=answer','h323-call-type=Telephony','','','','h323-gw-id=Router.','0','0','1258625016')
?Debug : Nov 19 12:03:36 Radius: Dynamic IP binding not called because ip or slink is null ! ip <0> slink <3>
?Debug : Nov 19 12:03:50 UTM5 DBA: DBAccess instance created
?Debug : Nov 19 12:03:50 DBA:Ctx: Looking for free context
?Debug : Nov 19 12:03:50 DBCtx: <679515136> SQL query: BEGIN
?Debug : Nov 19 12:03:50 DBCtx: DB transaction begin
?Debug : Nov 19 12:03:50 DBCtx: <679515136> SQL SELECT query: SELECT id,pool_id,secret,balance,currency,expiration,days,is_used,service_id,is_blocked FROM card_info WHERE secret='000397717964'
?Debug : Nov 19 12:03:50 DBCtx: <679515136> SQL SELECT query: SELECT value FROM utm5_settings WHERE variable='card_user_prefix'
?Debug : Nov 19 12:03:50 DBCtx: <679515136> SQL SELECT query: SELECT id,pool_id,secret,balance,currency,expiration,days,is_used,service_id,is_blocked FROM card_info WHERE id='3'
?Debug : Nov 19 12:03:50 DBCtx: <679515136> SQL SELECT query: SELECT pool_id,cards,cards_used,first_update,last_update FROM card_pool_info WHERE pool_id='1'
?Debug : Nov 19 12:03:50 DBCtx: <679515136> SQL SELECT query: SELECT user_id FROM card_pool_owners WHERE pool_id ='1' AND is_deleted = 0
?Debug : Nov 19 12:03:50 DBCtx: <679515136> SQL SELECT query: SELECT id,pool_id,secret,balance,currency,expiration,days,is_used,service_id,is_blocked FROM card_info WHERE id='3'
Warn : Nov 19 12:03:50 UTM5 DBA: add_user_card_priv: card <3> is already used
?Debug : Nov 19 12:03:50 DBCtx: <679515136> SQL query: COMMIT
?Debug : Nov 19 12:03:50 DBCtx: DB transaction commit
?Debug : Nov 19 12:03:50 DBA:Ctx: Pushing back free context
-Stats : Nov 19 12:03:50 UTM5 DBA: Stats: Uptime: 00:00:00. Events: 0; Errors: 0
?Debug : Nov 19 12:03:56 DBCtx: <679506944> SQL query: INSERT INTO tel_sessions_detail(dhs_sess_id,disc_per_id,slink_id,recv_date,account_id,trange_id,duration,base_cost,sum_cost) VALUES('10','3','3','1258625036','3','0','20','0','0')
?Debug : Nov 19 12:03:56 UTM5 DBA: DBAccess instance created
?Debug : Nov 19 12:03:56 DBA:Ctx: Looking for free context
?Debug : Nov 19 12:03:56 DBCtx: <679511040> SQL query: BEGIN
?Debug : Nov 19 12:03:56 DBCtx: DB transaction begin
?Debug : Nov 19 12:03:56 UTM5 DBA: discount_from_account tel zoneid <0> h.base_cost <0.000000>
?Debug : Nov 19 12:03:56 DBCtx: <679506944> SQL query: UPDATE dtagg_telephony SET discounted='0.000000',discounted_without_tax='0.000000', duration='68' WHERE id='1'
?Debug : Nov 19 12:03:56 UTM5 DBA: Charge:0.000000 p.u. for link:3 account 3
?Debug : Nov 19 12:03:56 DBCtx: <679511040> SQL query: UPDATE accounts SET balance='1' WHERE id = '3'
?Debug : Nov 19 12:03:56 DBCtx: <679511040> SQL query: INSERT INTO discount_transactions_all(account_id,incoming_rest,outgoing_rest,discount,discount_with_tax,service_id,service_type,slink_id,discount_date,charge_type,discount_period_id) VALUES('3','1','1','0','0','1','6','3','1258625036','6','3')
?Debug : Nov 19 12:03:56 UTM5 DBA: Checking for rehash: flags 3, balance 1.000 (old 1.000), credit 0.000
?Debug : Nov 19 12:03:56 DBAGiga: Rehash: Target: 10; Action: 1; Ptr: bc7e8a0c
?Debug : Nov 19 12:03:56 Radius: Account '3': 1.000/0.000 send...
?Debug : Nov 19 12:03:56 HSPlugin: Rehash: Target: 10; Action: 1; Ptr: bc7e8a0c
?Debug : Nov 19 12:03:56 BusLogic: BLM(37) pushed (comment: ruh block)
?Debug : Nov 19 12:03:56 DBCtx: <679511040> SQL query: COMMIT
?Debug : Nov 19 12:03:56 BusLogic: try to execute 37
?Debug : Nov 19 12:03:56 BusLogic: hw_block_handler with code 37
?Debug : Nov 19 12:03:56 BusLogic: finished unknown
?Debug : Nov 19 12:03:56 DBCtx: DB transaction commit
?Debug : Nov 19 12:03:56 DBA:Ctx: Pushing back free context
-Stats : Nov 19 12:03:56 UTM5 DBA: Stats: Uptime: 00:00:00. Events: 0; Errors: 0
?Debug : Nov 19 12:03:56 Radius: edit_session_log id <2> input octets <0> output octet <60480>
?Debug : Nov 19 12:03:56 Radius: session log with id <2> found in the cache
?Debug : Nov 19 12:03:56 DBCtx: <679506944> SQL query: UPDATE tel_sessions_log SET account_id='3', slink_id='3', last_update_date='1258625036', Acct_Status_Type='2', Acct_Input_Packets ='0', Acct_Input_Octets ='0', Acct_Input_Gigawords ='0', Acct_Output_Packets ='252', Acct_Output_Octets ='60480', Acct_Output_Gigawords ='0', h323_connect_time='', Acct_Terminate_Cause='0', h323_disconnect_cause='h323-disconnect-cause=11', Acct_Session_Time ='20' WHERE id='10'
?Debug : Nov 19 12:03:56 Radius: id2core removing key <2>
Код: Выделить всё
?Debug : Nov 19 12:03:36 RADIUS DBA: NAS found. Data size <0>
?Debug : Nov 19 12:03:36 AcctServer: Acct packet with session ID: 00000042
?Debug : Nov 19 12:03:36 RADIUS DBA: NAS found. Data size <0>
?Debug : Nov 19 12:03:36 AcctServer: Acct-Start packet
?Debug : Nov 19 12:03:36 AcctServer: Acct-Start: User <74012>
?Debug : Nov 19 12:03:36 AcctServer: Acct-Session-Time (46) not present in accounting packet.
?Debug : Nov 19 12:03:36 RADIUS DBA: Info for login <74012> found. type <3>
?Debug : Nov 19 12:03:36 RADIUS DBA: Password found for tel login:74012
?Debug : Nov 19 12:03:36 RADIUS DBA: info for user found. type <3> info addr <677436416>
?Debug : Nov 19 12:03:36 RADIUS DBA: search_user_info return info <677436416>
?Debug : Nov 19 12:03:36 RADIUS DBA: search_user_info return valid info
?Debug : Nov 19 12:03:36 RADIUS DBA: Setting interim interval <0> for session id <00000042>
?Debug : Nov 19 12:03:36 RADIUS DBA: TELTARIFF: called number <570235> calling number <74012> direction id <0> zone id <0>
?Debug : Nov 19 12:03:36 RADIUS DBA: tel.session_count incremented. value <1>
?Debug : Nov 19 12:03:36 RADIUS DBA: Calling send_session_log_init_sync ...
?Debug : Nov 19 12:03:36 RADIUS Stream[plugin]: send_session_log_init_sync
?Debug : Nov 19 12:03:36 RADIUS Stream[plugin]: init log id <2>
?Debug : Nov 19 12:03:36 AcctServer: Reply packet dump: RPacket:
Code: 5; ID: 99
?Debug : Nov 19 12:03:36 RadiusSocket: Moving RADIUS packet into send queue
?Debug : Nov 19 12:03:36 RadiusSocket: RADIUS raw data sent
?Debug : Nov 19 12:03:36 AcctServer: Next...
?Debug : Nov 19 12:03:36 RadiusSocket: Waiting for RADIUS raw data
?Debug : Nov 19 12:03:49 RADIUS DBA: No interim update enabled session <2> found. Setting to default (if enabled).
?Debug : Nov 19 12:03:50 RadiusSocket: RADIUS packet successfully received
?Debug : Nov 19 12:03:50 RadiusSocket: RADIUS raw data obtained
?Debug : Nov 19 12:03:50 RADIUS Packet: Size <187>; HDR.Size <187>
?Debug : Nov 19 12:03:50 AuthServer: Recv...
?Debug : Nov 19 12:03:50 AuthServer: Packet from NAS <192.168.254.2>
?Debug : Nov 19 12:03:50 RADIUS DBA: NAS found. Data size <0>
?Debug : Nov 19 12:03:50 AuthServer: Packet from <192.168.254.2> packet dump: RPacket:
Code: 1; ID: 17
<Vendor: 0; Attr: 1>[4]: 30303033
<Vendor: 0; Attr: 2>[16]: 8c7317d63c44eb690655a9bd4819dc43
<Vendor: 0; Attr: 4>[4]: c0a8fe02
<Vendor: 0; Attr: 5>[4]: 00000000
<Vendor: 0; Attr: 6>[4]: 00000001
<Vendor: 0; Attr: 31>[5]: 3734303132
<Vendor: 0; Attr: 61>[4]: 00000000
<Vendor: 9; Attr: 1>[29]: 683332332d6976722d6f75743d7472616e73616374696f6e49443a3137
<Vendor: 9; Attr: 2>[11]: 4953444e20303a443a3238
<Vendor: 9; Attr: 24>[48]: 683332332d636f6e662d69643d4133343846344234204434323931314445203830334241453232203431384534414330
?Debug : Nov 19 12:03:50 AuthServer: User <0003> connecting
?Debug : Nov 19 12:03:50 AuthServer: Session for sessionid <0003> not found in <192.168.254.2> cache
ERROR : Nov 19 12:03:50 RADIUS DBA: Can't find login <0003>
?Debug : Nov 19 12:03:50 RADIUS DBA: Searching card login <000000003>
ERROR : Nov 19 12:03:50 RADIUS DBA: Can't find card login <000000003>
?Debug : Nov 19 12:03:50 AuthServer: Attempt to add new Card user: <0003>
?Debug : Nov 19 12:03:50 AuthServer: Skiping non-digit symbols
?Debug : Nov 19 12:03:50 RADIUS DBA: Sending Auto-Add Request for Card-ID: 0003
?Debug : Nov 19 12:03:50 RADIUS Stream[plugin]: Ping reply received
?Debug : Nov 19 12:03:50 RADIUS Stream[plugin]: Got User-Autoadd id <0>
?Debug : Nov 19 12:03:50 AuthServer: Got AutoAdd 0 UID from core.
Info : Nov 19 12:03:51 AuthServer: Retry:0 to find user <0003>
ERROR : Nov 19 12:03:51 RADIUS DBA: Can't find login <0003>
?Debug : Nov 19 12:03:51 RADIUS DBA: Searching card login <000000003>
ERROR : Nov 19 12:03:51 RADIUS DBA: Can't find card login <000000003>
Info : Nov 19 12:03:52 AuthServer: Retry:1 to find user <0003>
ERROR : Nov 19 12:03:52 RADIUS DBA: Can't find login <0003>
?Debug : Nov 19 12:03:52 RADIUS DBA: Searching card login <000000003>
ERROR : Nov 19 12:03:52 RADIUS DBA: Can't find card login <000000003>
Info : Nov 19 12:03:53 AuthServer: Retry:2 to find user <0003>
ERROR : Nov 19 12:03:53 RADIUS DBA: Can't find login <0003>
?Debug : Nov 19 12:03:53 RADIUS DBA: Searching card login <000000003>
ERROR : Nov 19 12:03:53 RADIUS DBA: Can't find card login <000000003>
Warn : Nov 19 12:03:53 AuthServer: Errors adding card <0003>. Rehash failed
ERROR : Nov 19 12:03:53 AuthServer: No data for User <0003> found.
?Debug : Nov 19 12:03:53 AuthServer: Auth reply: RPacket:
Code: 3; ID: 17
<Vendor: 0; Attr: 18>[21]: 417574686f72697a6174696f6e206661696c65642e
<Vendor: 9; Attr: 103>[19]: 683332332d72657475726e2d636f64653d2d31
?Debug : Nov 19 12:03:53 RADIUS Packet: raw data constructed! size <70>
?Debug : Nov 19 12:03:53 RadiusSocket: Moving RADIUS packet into send queue
?Debug : Nov 19 12:03:53 RadiusSocket: RADIUS raw data sent
?Debug : Nov 19 12:03:53 AuthServer: Next...
?Trace : Nov 19 12:03:53 AuthServer: Process loop step
?Debug : Nov 19 12:03:53 RadiusSocket: Waiting for RADIUS raw data
?Debug : Nov 19 12:03:56 RadiusSocket: RADIUS packet successfully received
?Debug : Nov 19 12:03:56 RadiusSocket: RADIUS raw data obtained
?Debug : Nov 19 12:03:56 RADIUS Packet: Size <1142>; HDR.Size <1142>
?Debug : Nov 19 12:03:56 AcctServer: Recv...
?Debug : Nov 19 12:03:56 AcctServer: Packet from <192.168.254.2> packet dump: RPacket:
Code: 4; ID: 100
<Vendor: 0; Attr: 1>[4]: 30303033
<Vendor: 0; Attr: 4>[4]: c0a8fe02
<Vendor: 0; Attr: 5>[4]: 00000000
<Vendor: 0; Attr: 6>[4]: 00000001
<Vendor: 0; Attr: 30>[6]: 353730323335
<Vendor: 0; Attr: 31>[5]: 3734303132
<Vendor: 0; Attr: 40>[4]: 00000002
<Vendor: 0; Attr: 41>[4]: 00000000
<Vendor: 0; Attr: 42>[4]: 00000000
<Vendor: 0; Attr: 43>[4]: 0000ec40
<Vendor: 0; Attr: 44>[8]: 3030303030303432
<Vendor: 0; Attr: 45>[4]: 00000001
<Vendor: 0; Attr: 46>[4]: 00000014
<Vendor: 0; Attr: 47>[4]: 00000000
<Vendor: 0; Attr: 48>[4]: 000000fc
<Vendor: 0; Attr: 61>[4]: 00000000
<Vendor: 9; Attr: 1>[57]: 683332332d696e636f6d696e672d636f6e662d69643d4133343846344234204434323931314445203830334241453232203431384534414330
<Vendor: 9(0); Attr: 1>[22]: 737562736372696265723d526567756c61724c696e65
<Vendor: 9(1); Attr: 1>[31]: 67772d7278642d63646e3d746f6e3a302c6e70693a302c233a353730323335
<Vendor: 9(2); Attr: 1>[24]: 63616c6c696e672d70617274792d63617465676f72793d39
<Vendor: 9(3); Attr: 1>[25]: 7472616e736d697373696f6e2d6d656469756d2d7265713d30
<Vendor: 9(4); Attr: 1>[27]: 683332332d6976722d6f75743d5461726966663a556e6b6e6f776e
<Vendor: 9(5); Attr: 1>[16]: 72656c656173652d736f757263653d31
<Vendor: 9(6); Attr: 1>[30]: 67772d7278642d63676e3d746f6e3a302c6e70693a302c233a3734303132
<Vendor: 9(7); Attr: 1>[15]: 636861726765642d756e6974733d30
<Vendor: 9(8); Attr: 1>[30]: 646973636f6e6e6563742d746578743d7573657220627573792028313729
<Vendor: 9(9); Attr: 1>[18]: 706565722d616464726573733d3734303132
<Vendor: 9(10); Attr: 1>[16]: 696e666f2d747970653d737065656368
<Vendor: 9(11); Attr: 1>[9]: 706565722d69643d31
<Vendor: 9(12); Attr: 1>[16]: 706565722d69662d696e6465783d3736
<Vendor: 9(13); Attr: 1>[19]: 6c6f676963616c2d69662d696e6465783d3430
<Vendor: 9(14); Attr: 1>[13]: 61636f6d2d6c6576656c3d3231
<Vendor: 9(15); Attr: 1>[24]: 636f6465722d747970652d726174653d67373131756c6177
<Vendor: 9(16); Attr: 1>[22]: 6e6f6973652d6c6576656c3d34323934393637323132
<Vendor: 9(17); Attr: 1>[26]: 766f6963652d74782d6475726174696f6e3d3131363730206d73
<Vendor: 9(18); Attr: 1>[20]: 74782d6475726174696f6e3d3131363730206d73
<Vendor: 9; Attr: 2>[11]: 4953444e20303a443a3238
<Vendor: 9; Attr: 24>[48]: 683332332d636f6e662d69643d4133343846344234204434323931314445203830334241453232203431384534414330
<Vendor: 9; Attr: 25>[48]: 683332332d73657475702d74696d653d31323a30333a33362e3539322045455420546875204e6f762031392032303039
<Vendor: 9; Attr: 26>[23]: 683332332d63616c6c2d6f726967696e3d616e73776572
<Vendor: 9; Attr: 27>[24]: 683332332d63616c6c2d747970653d54656c6570686f6e79
<Vendor: 9; Attr: 28>[50]: 683332332d636f6e6e6563742d74696d653d31323a30333a33362e3630362045455420546875204e6f762031392032303039
<Vendor: 9; Attr: 29>[53]: 683332332d646973636f6e6e6563742d74696d653d31323a30333a35362e3133372045455420546875204e6f762031392032303039
<Vendor: 9; Attr: 30>[24]: 683332332d646973636f6e6e6563742d63617573653d3131
<Vendor: 9; Attr: 31>[20]: 683332332d766f6963652d7175616c6974793d30
<Vendor: 9; Attr: 33>[18]: 683332332d67772d69643d526f757465722e
?Debug : Nov 19 12:03:56 RADIUS DBA: NAS found. Data size <0>
?Debug : Nov 19 12:03:56 AcctServer: Acct packet with session ID: 00000042
?Debug : Nov 19 12:03:56 RADIUS DBA: NAS found. Data size <0>
?Debug : Nov 19 12:03:56 AcctServer: Acct-Stop packet
?Debug : Nov 19 12:03:56 RADIUS DBA: Session erase ... login type <3>
?Debug : Nov 19 12:03:56 RADIUS DBA: login type login_tel
?Debug : Nov 19 12:03:56 RADIUS DBA: Calling tel_calculate cost. session_time_not_present <0> NOW <1258625036>
?Debug : Nov 19 12:03:56 RADIUS Tarif: UT for telephony called. tkey:0 start:1258625016 stop:1258625036
?Debug : Nov 19 12:03:56 RADIUS Tarif: Telephony service <1> free time <5>
?Debug : Nov 19 12:03:56 RADIUS Tarif: UT cost_info sum:0.0000 setup_time <1258625016>
?Debug : Nov 19 12:03:56 RADIUS DBA: VoIP Discount: TR ID 0: 0.000 for 20 sec setup_time <1258625016>
?Debug : Nov 19 12:03:56 RADIUS Tarif: UT tkey <0> downloaded <46>
?Debug : Nov 19 12:03:56 RADIUS DBA: VoIP calculated cost: 0.000
?Debug : Nov 19 12:03:56 RADIUS Stream[plugin]: finish log id <2>
?Debug : Nov 19 12:03:56 AcctServer: Reply packet dump: RPacket:
Code: 5; ID: 100
про других пользователей:
для регистрации шлюза заведены 2 пользователя
1 - cisco - для регистрации его на ГейтКипере
2 - 74012 - для регистрации при звонке - иначе сыпятся ошибки, мол неизвестный логин/пароль в логах
Им обоим добавлена услуга телефонии.
Возможно у меня где то в этом косяк, но понять пока не могу. Может кто сможет подсказать более точно?
-
mobilesfinks
- Сообщения: 14
- Зарегистрирован: Пт ноя 13, 2009 13:56
Было что то подобное а точнее не авторизовывался карточный пользователь.
Правда сделано немного подругому у нас:
Netup <---> Asterisk
Вобщем Астериск авторизовывался через радиус на НетАпе .
Скрипты писал сам на perl с модулем Authen::Radius
Там все просто примеры можно найти в нете.
И вобщем дело было в нправильных словаярях(dictionary) для радиуса.
Долил в словари недостающие - все завелось и прекрасно (3тьфу) работает.
Такое может быть если на сервере раньше стояли другие радиусы и оставили свои словари.
ИМХО от H323 пора уходить на SIP. Давно уже пришел к этому выводу. И еще астериск - это пластилин из которого можно слепить все что угодно без особых проблем (в моем примере это карточная платформа).
В случае, если сервером выступает Cisco возможно так же не хватает каких либо аттрибутов в процессе авторизации. Можно попробовать посмотреть процесс авторизации следующей командой:
Еще может быть не указан в биллинге параметр card_tel_uid_len.
Насколько я понимаю цыска делит введенный пин-код на логин и пароль, в частности пин-код может быть длиной 10 цифр и первые 4 могут быть логином а последние 6 цифр будут представлены в биллинг как пароль.
В моем случае пин-код восьмизначный и делится так 4 цифры - логин и 4 - пароль.
Поэтому параметр card_tel_uid_len у меня имеет значение 4.
Другими словами card_tel_uid_len - это количество первых цифр из пин-кода отрезаются для логина.
Правда сделано немного подругому у нас:
Netup <---> Asterisk
Вобщем Астериск авторизовывался через радиус на НетАпе .
Скрипты писал сам на perl с модулем Authen::Radius
Там все просто примеры можно найти в нете.
И вобщем дело было в нправильных словаярях(dictionary) для радиуса.
Долил в словари недостающие - все завелось и прекрасно (3тьфу) работает.
Такое может быть если на сервере раньше стояли другие радиусы и оставили свои словари.
ИМХО от H323 пора уходить на SIP. Давно уже пришел к этому выводу. И еще астериск - это пластилин из которого можно слепить все что угодно без особых проблем (в моем примере это карточная платформа).
В случае, если сервером выступает Cisco возможно так же не хватает каких либо аттрибутов в процессе авторизации. Можно попробовать посмотреть процесс авторизации следующей командой:
Код: Выделить всё
term mon
debug radius authentication
Насколько я понимаю цыска делит введенный пин-код на логин и пароль, в частности пин-код может быть длиной 10 цифр и первые 4 могут быть логином а последние 6 цифр будут представлены в биллинг как пароль.
В моем случае пин-код восьмизначный и делится так 4 цифры - логин и 4 - пароль.
Поэтому параметр card_tel_uid_len у меня имеет значение 4.
Другими словами card_tel_uid_len - это количество первых цифр из пин-кода отрезаются для логина.
-
mobilesfinks
- Сообщения: 14
- Зарегистрирован: Пт ноя 13, 2009 13:56
да данного параметра в биллинге не указанно, но в логах радиуса он же ищет пользователя с данным количеством символовcard_tel_uid_len
согласен про SIP, но я пока в этом дуб и мне хотя бы имеющийся конфиг настроить, иначе это затягивается ещё больше.
зы: добавил данный параметр в биллинг, результат тот же
вот что монитор показал
Код: Выделить всё
.Nov 27 09:40:08.176: RADIUS/ENCODE(0000003B):Orig. component type = VOICE
.Nov 27 09:40:08.176: RADIUS(0000003B): Using existing nas_port 0
.Nov 27 09:40:08.176: RADIUS(0000003B): Config NAS IP: 0.0.0.0
.Nov 27 09:40:08.176: RADIUS/ENCODE(0000003B): acct_session_id: 83
.Nov 27 09:40:08.176: RADIUS(0000003B): sending
.Nov 27 09:40:08.176: RADIUS/ENCODE: Best Local IP-Address 192.168.254.2 for Radius-Server 192.168.254.1
.Nov 27 09:40:08.176: RADIUS(0000003B): Send Access-Request to 192.168.254.1:1812 id 1645/17, len 187
.Nov 27 09:40:08.176: RADIUS: authenticator 35 6B 4A 47 56 0F 4A B1 - CF 39 9E 53 57 BC 9E 51
.Nov 27 09:40:08.176: RADIUS: User-Name [1] 6 "0003"
.Nov 27 09:40:08.176: RADIUS: User-Password [2] 18 *
.Nov 27 09:40:08.176: RADIUS: Vendor, Cisco [26] 56
.Nov 27 09:40:08.176: RADIUS: Conf-Id [24] 50 "h323-conf-id=A657A24C DA6F11DE 804ABEAD 00978D9D"
.Nov 27 09:40:08.180: RADIUS: Vendor, Cisco [26] 37
.Nov 27 09:40:08.180: RADIUS: Cisco AVpair [1] 31 "h323-ivr-out=transactionID:16"
.Nov 27 09:40:08.180: RADIUS: Calling-Station-Id [31] 7 "74012"
.Nov 27 09:40:08.180: RADIUS: NAS-Port-Type [61] 6 Async [0]
.Nov 27 09:40:08.180: RADIUS: Vendor, Cisco [26] 19
.Nov 27 09:40:08.180: RADIUS: cisco-nas-port [2] 13 "ISDN 0:D:19"
.Nov 27 09:40:08.180: RADIUS: NAS-Port [5] 6 0
.Nov 27 09:40:08.180: RADIUS: Service-Type [6] 6 Login [1]
.Nov 27 09:40:08.180: RADIUS: NAS-IP-Address [4] 6 192.168.254.2
.Nov 27 09:40:08.496: RADIUS: acct-delay-time for 40546000 (at 4054621C) now 15
.Nov 27 09:40:08.496: RADIUS: Retransmit to (192.168.254.1:1812,1813) for id 1646/194
.Nov 27 09:40:11.228: RADIUS: Received from id 1645/17 192.168.254.1:1812, Access-Reject, len 70
.Nov 27 09:40:11.228: RADIUS: authenticator B6 96 A7 37 99 7D 36 CE - BD 43 2F BD 7F 2B 69 79
.Nov 27 09:40:11.228: RADIUS: Reply-Message [18] 23
.Nov 27 09:40:11.228: RADIUS: 41 75 74 68 6F 72 69 7A 61 74 69 6F 6E 20 66 61 [Authorization fa]
.Nov 27 09:40:11.228: RADIUS: 69 6C 65 64 2E [iled.]
.Nov 27 09:40:11.228: RADIUS: Vendor, Cisco [26] 27
.Nov 27 09:40:11.228: RADIUS: h323-return-code [103] 21 "h323-return-code=-1"
.Nov 27 09:40:11.232: RADIUS(0000003B): Received from id 1645/17
.Nov 27 09:40:11.232: RADIUS/DECODE: Reply-Message fragments, 21, total 21 bytes
.Nov 27 09:40:13.496: RADIUS: acct-delay-time for 40546000 (at 4054621C) now 20
.Nov 27 09:40:13.496: RADIUS: No response from (192.168.254.1:1812,1813) for id 1646/194
где их глянуть?И вобщем дело было в нправильных словаярях(dictionary) для радиуса.
Долил в словари недостающие - все завелось и прекрасно (3тьфу) работает.
вот полный лог соединения
Код: Выделить всё
.Nov 27 09:39:53.479: RADIUS/ENCODE(0000003B):Orig. component type = VOICE
.Nov 27 09:39:53.479: RADIUS(0000003B): Storing nasport 0 in rad_db
.Nov 27 09:39:53.479: RADIUS(0000003B): Config NAS IP: 0.0.0.0
.Nov 27 09:39:53.479: RADIUS(0000003B): sending
.Nov 27 09:39:53.487: RADIUS/ENCODE: Best Local IP-Address 192.168.254.2 for Radius-Server 192.168.254.1
.Nov 27 09:39:53.487: RADIUS(0000003B): Send Accounting-Request to 192.168.254.1:1813 id 1646/191, len 546
.Nov 27 09:39:53.487: RADIUS: authenticator 3E 90 8D 48 AB 0A 0A 47 - CF E2 D3 B7 6D A4 69 EE
.Nov 27 09:39:53.487: RADIUS: Acct-Session-Id [44] 10 "00000053"
.Nov 27 09:39:53.487: RADIUS: Calling-Station-Id [31] 7 "74012"
.Nov 27 09:39:53.487: RADIUS: Called-Station-Id [30] 8 "570235"
.Nov 27 09:39:53.487: RADIUS: Vendor, Cisco [26] 57
.Nov 27 09:39:53.487: RADIUS: h323-setup-time [25] 51 "h323-setup-time=.11:39:53.475 EET Fri Nov 27 2009"
.Nov 27 09:39:53.487: RADIUS: Vendor, Cisco [26] 26
.Nov 27 09:39:53.487: RADIUS: h323-gw-id [33] 20 "h323-gw-id=Router."
.Nov 27 09:39:53.487: RADIUS: Vendor, Cisco [26] 56
.Nov 27 09:39:53.487: RADIUS: Conf-Id [24] 50 "h323-conf-id=A657A24C DA6F11DE 804ABEAD 00978D9D"
.Nov 27 09:39:53.491: RADIUS: Vendor, Cisco [26] 31
.Nov 27 09:39:53.491: RADIUS: h323-call-origin [26] 25 "h323-call-origin=answer"
.Nov 27 09:39:53.491: RADIUS: Vendor, Cisco [26] 32
.Nov 27 09:39:53.491: RADIUS: h323-call-type [27] 26 "h323-call-type=Telephony"
.Nov 27 09:39:53.491: RADIUS: Vendor, Cisco [26] 65
.Nov 27 09:39:53.491: RADIUS: Cisco AVpair [1] 59 "h323-incoming-conf-id=A657A24C DA6F11DE 804ABEAD 00978D9D"
.Nov 27 09:39:53.491: RADIUS: Vendor, Cisco [26] 30
.Nov 27 09:39:53.491: RADIUS: Cisco AVpair [1] 24 "subscriber=RegularLine"
.Nov 27 09:39:53.491: RADIUS: Vendor, Cisco [26] 39
.Nov 27 09:39:53.491: RADIUS: Cisco AVpair [1] 33 "gw-rxd-cdn=ton:0,npi:0,#:570235"
.Nov 27 09:39:53.491: RADIUS: Vendor, Cisco [26] 32
.Nov 27 09:39:53.491: RADIUS: Cisco AVpair [1] 26 "calling-party-category=9"
.Nov 27 09:39:53.491: RADIUS: Vendor, Cisco [26] 33
.Nov 27 09:39:53.491: RADIUS: Cisco AVpair [1] 27 "transmission-medium-req=0"
.Nov 27 09:39:53.491: RADIUS: User-Name [1] 7 "74012"
.Nov 27 09:39:53.491: RADIUS: Vendor, Cisco [26] 32
.Nov 27 09:39:53.491: RADIUS: Cisco AVpair [1] 26 "connect-progress=Call Up"
.Nov 27 09:39:53.491: RADIUS: Acct-Authentic [45] 6 noval0 [0]
.Nov 27 09:39:53.491: RADIUS: Acct-Status-Type [40] 6 Start [1]
.Nov 27 09:39:53.491: RADIUS: NAS-Port-Type [61] 6 Async [0]
.Nov 27 09:39:53.491: RADIUS: Vendor, Cisco [26] 19
.Nov 27 09:39:53.491: RADIUS: cisco-nas-port [2] 13 "ISDN 0:D:19"
.Nov 27 09:39:53.491: RADIUS: NAS-Port [5] 6 0
.Nov 27 09:39:53.495: RADIUS: Service-Type [6] 6 Login [1]
.Nov 27 09:39:53.495: RADIUS: NAS-IP-Address [4] 6 192.168.254.2
.Nov 27 09:39:53.495: RADIUS: Acct-Delay-Time [41] 6 0
.Nov 27 09:39:53.519: %ISDN-6-CONNECT: Interface Serial0:18 is now connected to 74012 N/A
.Nov 27 09:39:58.496: RADIUS: acct-delay-time for 40546000 (at 4054621C) now 5
.Nov 27 09:39:58.496: RADIUS: Retransmit to (192.168.254.1:1812,1813) for id 1646/192
.Nov 27 09:40:03.496: RADIUS: acct-delay-time for 40546000 (at 4054621C) now 10
.Nov 27 09:40:03.496: RADIUS: Retransmit to (192.168.254.1:1812,1813) for id 1646/193
.Nov 27 09:40:08.176: RADIUS/ENCODE(0000003B):Orig. component type = VOICE
.Nov 27 09:40:08.176: RADIUS(0000003B): Using existing nas_port 0
.Nov 27 09:40:08.176: RADIUS(0000003B): Config NAS IP: 0.0.0.0
.Nov 27 09:40:08.176: RADIUS/ENCODE(0000003B): acct_session_id: 83
.Nov 27 09:40:08.176: RADIUS(0000003B): sending
.Nov 27 09:40:08.176: RADIUS/ENCODE: Best Local IP-Address 192.168.254.2 for Radius-Server 192.168.254.1
.Nov 27 09:40:08.176: RADIUS(0000003B): Send Access-Request to 192.168.254.1:1812 id 1645/17, len 187
.Nov 27 09:40:08.176: RADIUS: authenticator 35 6B 4A 47 56 0F 4A B1 - CF 39 9E 53 57 BC 9E 51
.Nov 27 09:40:08.176: RADIUS: User-Name [1] 6 "0003"
.Nov 27 09:40:08.176: RADIUS: User-Password [2] 18 *
.Nov 27 09:40:08.176: RADIUS: Vendor, Cisco [26] 56
.Nov 27 09:40:08.176: RADIUS: Conf-Id [24] 50 "h323-conf-id=A657A24C DA6F11DE 804ABEAD 00978D9D"
.Nov 27 09:40:08.180: RADIUS: Vendor, Cisco [26] 37
.Nov 27 09:40:08.180: RADIUS: Cisco AVpair [1] 31 "h323-ivr-out=transactionID:16"
.Nov 27 09:40:08.180: RADIUS: Calling-Station-Id [31] 7 "74012"
.Nov 27 09:40:08.180: RADIUS: NAS-Port-Type [61] 6 Async [0]
.Nov 27 09:40:08.180: RADIUS: Vendor, Cisco [26] 19
.Nov 27 09:40:08.180: RADIUS: cisco-nas-port [2] 13 "ISDN 0:D:19"
.Nov 27 09:40:08.180: RADIUS: NAS-Port [5] 6 0
.Nov 27 09:40:08.180: RADIUS: Service-Type [6] 6 Login [1]
.Nov 27 09:40:08.180: RADIUS: NAS-IP-Address [4] 6 192.168.254.2
.Nov 27 09:40:08.496: RADIUS: acct-delay-time for 40546000 (at 4054621C) now 15
.Nov 27 09:40:08.496: RADIUS: Retransmit to (192.168.254.1:1812,1813) for id 1646/194
.Nov 27 09:40:11.228: RADIUS: Received from id 1645/17 192.168.254.1:1812, Access-Reject, len 70
.Nov 27 09:40:11.228: RADIUS: authenticator B6 96 A7 37 99 7D 36 CE - BD 43 2F BD 7F 2B 69 79
.Nov 27 09:40:11.228: RADIUS: Reply-Message [18] 23
.Nov 27 09:40:11.228: RADIUS: 41 75 74 68 6F 72 69 7A 61 74 69 6F 6E 20 66 61 [Authorization fa]
.Nov 27 09:40:11.228: RADIUS: 69 6C 65 64 2E [iled.]
.Nov 27 09:40:11.228: RADIUS: Vendor, Cisco [26] 27
.Nov 27 09:40:11.228: RADIUS: h323-return-code [103] 21 "h323-return-code=-1"
.Nov 27 09:40:11.232: RADIUS(0000003B): Received from id 1645/17
.Nov 27 09:40:11.232: RADIUS/DECODE: Reply-Message fragments, 21, total 21 bytes
.Nov 27 09:40:13.496: RADIUS: acct-delay-time for 40546000 (at 4054621C) now 20
.Nov 27 09:40:13.496: RADIUS: No response from (192.168.254.1:1812,1813) for id 1646/194
.Nov 27 09:40:13.496: RADIUS/DECODE: parse response no app start; FAIL
.Nov 27 09:40:13.496: RADIUS/DECODE: parse response; FAIL
.Nov 27 09:40:13.636: %ISDN-6-DISCONNECT: Interface Serial0:18 disconnected from 74012 , call lasted 20 seconds
.Nov 27 09:40:13.656: RADIUS/ENCODE(0000003B):Orig. component type = VOICE
.Nov 27 09:40:13.656: RADIUS(0000003B): Using existing nas_port 0
.Nov 27 09:40:13.656: RADIUS(0000003B): Config NAS IP: 0.0.0.0
.Nov 27 09:40:13.656: RADIUS(0000003B): sending
.Nov 27 09:40:13.660: RADIUS/ENCODE: Best Local IP-Address 192.168.254.2 for Radius-Server 192.168.254.1
.Nov 27 09:40:13.660: RADIUS(0000003B): Send Accounting-Request to 192.168.254.1:1813 id 1646/196, len 1145
.Nov 27 09:40:13.660: RADIUS: authenticator 3B C2 BE A9 54 44 82 52 - 38 8F A6 4E 0E CE CC 15
.Nov 27 09:40:13.660: RADIUS: Acct-Session-Id [44] 10 "00000053"
.Nov 27 09:40:13.660: RADIUS: Calling-Station-Id [31] 7 "74012"
.Nov 27 09:40:13.660: RADIUS: Called-Station-Id [30] 8 "570235"
.Nov 27 09:40:13.660: RADIUS: Vendor, Cisco [26] 57
.Nov 27 09:40:13.660: RADIUS: h323-setup-time [25] 51 "h323-setup-time=.11:39:53.475 EET Fri Nov 27 2009"
.Nov 27 09:40:13.660: RADIUS: Vendor, Cisco [26] 26
.Nov 27 09:40:13.660: RADIUS: h323-gw-id [33] 20 "h323-gw-id=Router."
.Nov 27 09:40:13.660: RADIUS: Vendor, Cisco [26] 56
.Nov 27 09:40:13.660: RADIUS: Conf-Id [24] 50 "h323-conf-id=A657A24C DA6F11DE 804ABEAD 00978D9D"
.Nov 27 09:40:13.660: RADIUS: Vendor, Cisco [26] 31
.Nov 27 09:40:13.660: RADIUS: h323-call-origin [26] 25 "h323-call-origin=answer"
.Nov 27 09:40:13.660: RADIUS: Vendor, Cisco [26] 32
.Nov 27 09:40:13.664: RADIUS: h323-call-type [27] 26 "h323-call-type=Telephony"
.Nov 27 09:40:13.664: RADIUS: Vendor, Cisco [26] 65
.Nov 27 09:40:13.664: RADIUS: Cisco AVpair [1] 59 "h323-incoming-conf-id=A657A24C DA6F11DE 804ABEAD 00978D9D"
.Nov 27 09:40:13.664: RADIUS: Vendor, Cisco [26] 30
.Nov 27 09:40:13.664: RADIUS: Cisco AVpair [1] 24 "subscriber=RegularLine"
.Nov 27 09:40:13.664: RADIUS: Vendor, Cisco [26] 39
.Nov 27 09:40:13.664: RADIUS: Cisco AVpair [1] 33 "gw-rxd-cdn=ton:0,npi:0,#:570235"
.Nov 27 09:40:13.664: RADIUS: Vendor, Cisco [26] 32
.Nov 27 09:40:13.664: RADIUS: Cisco AVpair [1] 26 "calling-party-category=9"
.Nov 27 09:40:13.664: RADIUS: Vendor, Cisco [26] 33
.Nov 27 09:40:13.664: RADIUS: Cisco AVpair [1] 27 "transmission-medium-req=0"
.Nov 27 09:40:13.664: RADIUS: Vendor, Cisco [26] 59
.Nov 27 09:40:13.664: RADIUS: h323-connect-time [28] 53 "h323-connect-time=.11:39:53.483 EET Fri Nov 27 2009"
.Nov 27 09:40:13.664: RADIUS: Acct-Input-Octets [42] 6 0
.Nov 27 09:40:13.664: RADIUS: Acct-Output-Octets [43] 6 53520
.Nov 27 09:40:13.664: RADIUS: Acct-Input-Packets [47] 6 0
.Nov 27 09:40:13.664: RADIUS: Acct-Output-Packets [48] 6 223
.Nov 27 09:40:13.664: RADIUS: Acct-Session-Time [46] 6 20
.Nov 27 09:40:13.664: RADIUS: Vendor, Cisco [26] 62
.Nov 27 09:40:13.664: RADIUS: h323-disconnect-tim[29] 56 "h323-disconnect-time=.11:40:13.638 EET Fri Nov 27 2009"
.Nov 27 09:40:13.664: RADIUS: Vendor, Cisco [26] 32
.Nov 27 09:40:13.668: RADIUS: h323-disconnect-cau[30] 26 "h323-disconnect-cause=11"
.Nov 27 09:40:13.668: RADIUS: Vendor, Cisco [26] 35
.Nov 27 09:40:13.668: RADIUS: Cisco AVpair [1] 29 "h323-ivr-out=Tariff:Unknown"
.Nov 27 09:40:13.668: RADIUS: Vendor, Cisco [26] 24
.Nov 27 09:40:13.668: RADIUS: Cisco AVpair [1] 18 "release-source=1"
.Nov 27 09:40:13.668: RADIUS: Vendor, Cisco [26] 28
.Nov 27 09:40:13.668: RADIUS: h323-voice-quality [31] 22 "h323-voice-quality=0"
.Nov 27 09:40:13.668: RADIUS: Vendor, Cisco [26] 38
.Nov 27 09:40:13.668: RADIUS: Cisco AVpair [1] 32 "gw-rxd-cgn=ton:0,npi:0,#:74012"
.Nov 27 09:40:13.668: RADIUS: Vendor, Cisco [26] 23
.Nov 27 09:40:13.668: RADIUS: Cisco AVpair [1] 17 "charged-units=0"
.Nov 27 09:40:13.668: RADIUS: Vendor, Cisco [26] 38
.Nov 27 09:40:13.668: RADIUS: Cisco AVpair [1] 32 "disconnect-text=user busy (17)"
.Nov 27 09:40:13.668: RADIUS: Vendor, Cisco [26] 26
.Nov 27 09:40:13.668: RADIUS: Cisco AVpair [1] 20 "peer-address=74012"
.Nov 27 09:40:13.668: RADIUS: Vendor, Cisco [26] 24
.Nov 27 09:40:13.668: RADIUS: Cisco AVpair [1] 18 "info-type=speech"
.Nov 27 09:40:13.668: RADIUS: Vendor, Cisco [26] 17
.Nov 27 09:40:13.668: RADIUS: Cisco AVpair [1] 11 "peer-id=1"
.Nov 27 09:40:13.668: RADIUS: Vendor, Cisco [26] 24
.Nov 27 09:40:13.668: RADIUS: Cisco AVpair [1] 18 "peer-if-index=76"
.Nov 27 09:40:13.668: RADIUS: Vendor, Cisco [26] 27
.Nov 27 09:40:13.668: RADIUS: Cisco AVpair [1] 21 "logical-if-index=31"
.Nov 27 09:40:13.668: RADIUS: Vendor, Cisco [26] 21
.Nov 27 09:40:13.672: RADIUS: Cisco AVpair [1] 15 "acom-level=30"
.Nov 27 09:40:13.672: RADIUS: Vendor, Cisco [26] 32
.Nov 27 09:40:13.672: RADIUS: Cisco AVpair [1] 26 "coder-type-rate=g711ulaw"
.Nov 27 09:40:13.672: RADIUS: Vendor, Cisco [26] 30
.Nov 27 09:40:13.672: RADIUS: Cisco AVpair [1] 24 "noise-level=4294967212"
.Nov 27 09:40:13.672: RADIUS: Vendor, Cisco [26] 34
.Nov 27 09:40:13.672: RADIUS: Cisco AVpair [1] 28 "voice-tx-duration=12800 ms"
.Nov 27 09:40:13.672: RADIUS: Vendor, Cisco [26] 28
.Nov 27 09:40:13.672: RADIUS: Cisco AVpair [1] 22 "tx-duration=12800 ms"
.Nov 27 09:40:13.672: RADIUS: User-Name [1] 6 "0003"
.Nov 27 09:40:13.672: RADIUS: Acct-Authentic [45] 6 RADIUS [1]
.Nov 27 09:40:13.672: RADIUS: Acct-Status-Type [40] 6 Stop [2]
.Nov 27 09:40:13.672: RADIUS: NAS-Port-Type [61] 6 Async [0]
.Nov 27 09:40:13.672: RADIUS: Vendor, Cisco [26] 19
.Nov 27 09:40:13.672: RADIUS: cisco-nas-port [2] 13 "ISDN 0:D:19"
.Nov 27 09:40:13.672: RADIUS: NAS-Port [5] 6 0
.Nov 27 09:40:13.672: RADIUS: Service-Type [6] 6 Login [1]
.Nov 27 09:40:13.672: RADIUS: NAS-IP-Address [4] 6 192.168.254.2
.Nov 27 09:40:13.672: RADIUS: Acct-Delay-Time [41] 6 0
.Nov 27 09:40:13.676: RADIUS: Received from id 1646/196 192.168.254.1:1813, Accounting-response, len 20
.Nov 27 09:40:13.676: RADIUS: authenticator 9F 4A 4A A8 16 FD F7 CC - CD A6 D4 1B B3 B5 7E A9