есть циска 5350, которая принимает pots звонки с PRI ISDN из PSTN.
прикручен IVR с tcl'ным скриптом и аудиофайлами.
когда приходит звонок, юзера просят ввести пинкод, который отсылается в радиус
на проверку
валидности пин-кода в mysql-базе. после этого юзер набирает номер и его звонок
терминируется по воипу.
всё хорошо всё отлично работает.
версия иоса: IOS (tm) 5350 Software (C5350-IS-M), Version 12.2(2)XB11, EARLY
DEPLOYMENT RELEASE SOFTWARE (fc1)
появилась необходимость накрутить тоже самое но на 2600-й циске. с двумя
FXS-портами
версия иоса:
IOS (tm) C2600 Software (C2600-IS3X-M), Version 12.3(13b), RELEASE SOFTWARE
(fc2)
вот куски конфига, делал всё по аналогии с 5350
aaa group server radius voip
server X.X.X.X auth-port 1812 acct-port 1813
!
aaa authentication login h323 group voip
aaa authorization exec default local group voip
aaa authorization exec h323 group voip
aaa authorization exec if-athen if-authenticated
aaa authorization network default group voip
aaa accounting update newinfo
aaa accounting network h323 stop-only group voip
aaa accounting connection h323 stop-only group voip
aaa session-id common
!
gw-accounting syslog
gw-accounting aaa
!
!
radius-server attribute 8 include-in-access-req
radius-server host X.X.X.X auth-port 1812 acct-port 1813 non-standard timeout
30 key 7 123123123123123123
radius-server timeout 7
radius-server vsa send accounting
radius-server vsa send authentication
!
call application voice ivr_pots_35-2 tftp://X.X.X.X/scripts/ivr_pots.tcl
call application voice ivr_pots_35-2 language 0 ru
call application voice ivr_pots_35-2 set-location ru 0 tftp://X.X.X.X/voip/ru/
!
voice-port 1/0/0
echo-cancel coverage 32
cptone RU
!
voice-port 1/0/1
echo-cancel coverage 32
cptone RU
dial-peer voice 108 voip
preference 1
destination-pattern 8...........
progress_ind setup enable 3
progress_ind progress enable 8
translate-outgoing called 87
voice-class codec 1
session target ipv4:X.X.X.X
tech-prefix 00
dtmf-relay h245-alphanumeric
ip qos dscp cs5 media
dial-peer voice 101 pots
application ivr_pots_35-2
incoming called-number 108
answer-address 108
port 1/0/0
втыкаем телефонный аппарат в fxs порт, согласно tcl-скрипту
в трубе появляется голос с приглашением ввести пинкод.
на 5350-й циске после ввода пинкода пользователю сообшается его текущий баланс
и предлагается позвонить.
используя тот же самый скрипт на 2610 циске происходит нечто странное.
вместо сообщения о текущем балансе сообщается "на линии перегрузка" и трубку
бросается.
вот дебаг радиуса и скрипта.
Sep 13 13:48:49 nt26xx01 413: *Mar 1 03:54:47.254: RADIUS: User-Name [1] 11 "17454117"
Sep 13 13:48:49 nt26xx01 414: *Mar 1 03:54:47.254: RADIUS: User-Password [2] 18 *
Sep 13 13:48:49 nt26xx01 415: *Mar 1 03:54:47.254: RADIUS: Vendor, Cisco [26] 56
Sep 13 13:48:49 nt26xx01 416: *Mar 1 03:54:47.254: RADIUS: Conf-Id [24] 50 "h323-conf-id=2AD8CA56 14F611CC 80209DB1 1B36C469"
Sep 13 13:48:49 nt26xx01 417: *Mar 1 03:54:47.254: RADIUS: Vendor, Cisco [26] 37
Sep 13 13:48:49 nt26xx01 418: *Mar 1 03:54:47.254: RADIUS: Cisco AVpair [1] 31 "h323-ivr-out=transactionID:16"
Sep 13 13:48:49 nt26xx01 419: *Mar 1 03:54:47.258: RADIUS: Calling-Station-Id[31] 5 "108"
Sep 13 13:48:49 nt26xx01 420: *Mar 1 03:54:47.258: RADIUS: NAS-Port-Type [61] 6 Async [0]
Sep 13 13:48:49 nt26xx01 421: *Mar 1 03:54:47.258: RADIUS: Vendor, Cisco [26] 17
Sep 13 13:48:49 nt26xx01 422: *Mar 1 03:54:47.258: RADIUS: cisco-nas-port [2] 11 "FXS 1/0/1"
Sep 13 13:48:49 nt26xx01 423: *Mar 1 03:54:47.258: RADIUS: NAS-Port [5] 6 0
Sep 13 13:48:49 nt26xx01 424: *Mar 1 03:54:47.262: RADIUS: Service-Type [6] 6 Login [1]
Sep 13 13:48:49 nt26xx01 425: *Mar 1 03:54:47.262: RADIUS: NAS-IP-Address [4] 6 212.92.136.140
Sep 13 13:48:49 nt26xx01 426: *Mar 1 03:54:47.334: RADIUS: Received from id 1645/17 212.92.136.35:1812, Access-Accept,len 76
Sep 13 13:48:49 nt26xx01 427: *Mar 1 03:54:47.338: RADIUS: authenticator 41 77 A5 C2 E3 9E CA 86 - 9A BB 34 92 A3 D0 5D 9A
Sep 13 13:48:49 nt26xx01 428: *Mar 1 03:54:47.338: RADIUS: Vendor, Cisco [26] 26
Sep 13 13:48:50 nt26xx01 429: *Mar 1 03:54:47.338: RADIUS: h323-return-code [103] 20 "h323-return-code=0"
Sep 13 13:48:50 nt26xx01 430: *Mar 1 03:54:47.338: RADIUS: Vendor, Cisco [26] 30
Sep 13 13:48:50 nt26xx01 431: *Mar 1 03:54:47.338: RADIUS: h323-credit-amount [101] 24 "h323-credit-amount=563"
Sep 13 13:48:50 nt26xx01 432: *Mar 1 03:54:47.342: RADIUS(0000000F): Received from id 1645/17
Sep 13 13:48:55 nt26xx01 433: *Mar 1 03:54:53.901:
%VOIPAAA-5-VOIP_CALL_HISTORY: CallLegType 1, ConnectionId 2AD8CA56 1
4F611CC 80209DB1 1B36C469, SetupTime *03:54:40.031 MSK Mon Mar 1 1993,
PeerAddress 108, PeerSubAddress , DisconnectCause 10 , DisconnectText normal call clearing (16), ConnectTime *03:54:40.101 MSK
Mon Mar 1 1993, DisconnectTime *03:54:53.891 MSK Mon Mar 1 1993, CallOrigin 2, ChargedUnits 0, InfoType 2,
TransmitPackets 456, TransmitBytes 72960, ReceivePackets 0, ReceiveBytes 0
т.е. из логов радиуса видно что на запрошенный пин был возвращен аксесс с кодом
0 и состояние счета.
после чего в на 5350 в обычных условиях происходил звонок. тут же просто
кладется трубка.
вот дебаг ivr скрипта
#debug voice ivr all
Sep 13 14:21:04 nt26xx01 775: *Mar 1 03:16:53.805: :/ani/
Sep 13 14:21:04 nt26xx01 776: *Mar 1 03:16:53.805: :[authorize]
Sep 13 14:21:04 nt26xx01 777: *Mar 1 03:16:53.809: authorization
Sep 13 14:21:04 nt26xx01 778: *Mar 1 03:16:53.809: account=173868117
Sep 13 14:21:04 nt26xx01 779: *Mar 1 03:16:53.809: password=unknown
Sep 13 14:21:04 nt26xx01 780: *Mar 1 03:16:53.809: destination=
Sep 13 14:21:04 nt26xx01 781: *Mar 1 03:16:53.897: ta_get_event: out of whileloop for event authorized
Sep 13 14:21:04 nt26xx01 782: *Mar 1 03:16:53.897: cid(4) ta_get_event returning authorized
Sep 13 14:21:04 nt26xx01 783: *Mar 1 03:16:53.897: :/getVariable/
Sep 13 14:21:04 nt26xx01 784: *Mar 1 03:16:53.897: "getVariable radius attr-name" is deprecated by "getVariable aaa attr-name returnInfo"
Sep 13 14:21:04 nt26xx01 785: *Mar 1 03:16:53.901: :[callID]
Sep 13 14:21:04 nt26xx01 786: *Mar 1 03:16:53.901: :/puts/
Sep 13 14:21:04 nt26xx01 787: *Mar 1 03:16:53.901: DEBUG: cid(4) app running change from oldstate=first_authorize to state=get_dest
Sep 13 14:21:04 nt26xx01 788: *Mar 1 03:16:53.913: :[callID]
Sep 13 14:21:04 nt26xx01 789: *Mar 1 03:16:53.913: :/puts/
Sep 13 14:21:04 nt26xx01 790: *Mar 1 03:16:53.913: DEBUG: do_get_dest: 4 : STARTED
Sep 13 14:21:04 nt26xx01 791: *Mar 1 03:16:53.921: :/getVariable/
Sep 13 14:21:04 nt26xx01 792: *Mar 1 03:16:53.921: "getVariable radius attr-name" is deprecated by "getVariable aaa attr-name returnInfo"
Sep 13 14:21:04 nt26xx01 793: *Mar 1 03:16:53.925: :/getVariable/
Sep 13 14:21:04 nt26xx01 794: *Mar 1 03:16:53.925: :[callID]
Sep 13 14:21:04 nt26xx01 795: *Mar 1 03:16:53.925: :/puts/
Sep 13 14:21:04 nt26xx01 796: *Mar 1 03:16:53.925: DEBUG: do_get_dest: 4: AMOUNT IS 563
Sep 13 14:21:04 nt26xx01 797: *Mar 1 03:16:53.929: ta_PlayPromptCmd() 00:16:53.894
Sep 13 14:21:04 nt26xx01 798:
Sep 13 14:21:04 nt26xx01 799: *Mar 1 03:16:53.929: ta_PlayPromptCmd. on incoming CallID=4
Sep 13 14:21:04 nt26xx01 800:
Sep 13 14:21:04 nt26xx01 801: *Mar 1 03:16:53.933: //-1//DPM :DP5:/pc_mc_createDynamicS: calloc mcDynamicS_t
Sep 13 14:21:04 nt26xx01 802: *Mar 1 03:16:53.933: //-1//DPM :DP5:/pc_mc_addToDynamicS: (1) ru_no_aaa.au
Sep 13 14:21:04 nt26xx01 803: *Mar 1 03:16:53.933: //-1//DPM :DP5:/pc_mc_addToDynamicS: Doing : ru_no_aaa.au
Sep 13 14:21:04 nt26xx01 804: *Mar 1 03:16:53.933: //-1//DPM :DP5:/pc_mc_addToDynamicS: Token : ru_no_aaa.au
Sep 13 14:21:04 nt26xx01 805: *Mar 1 03:16:53.933: //-1//MCM :/mc_createFromFileUrl: Getting a media content: name=ru_no_aaa.au
Sep 13 14:21:04 nt26xx01 806: url=tftp://212.92.136.35/voip-new/arcon_ru/ru_no_aaa.au
Sep 13 14:21:04 nt26xx01 807: load fast, load in foreground, fetchtimeout=-1
Sep 13 14:21:04 nt26xx01 808: maxage=-1, maxstale=-1
Sep 13 14:21:04 nt26xx01 809: *Mar 1 03:16:53.937: //-1//MCM :MC3:/mc_getFromUrlName: ru_no_aaa.au on ram
Sep 13 14:21:04 nt26xx01 810: *Mar 1 03:16:53.937: //-1//MCM :MC3:/mc_waitq_unlink: elm=83016DB8
Sep 13 14:21:04 nt26xx01 811: *Mar 1 03:16:53.937: //-1//MCM :MC3:/mc_waitq_unlink: prompt_wait=13692 prompt_active=0
Sep 13 14:21:04 nt26xx01 812:
Sep 13 14:21:04 nt26xx01 813: *Mar 1 03:16:53.937: //-1//MCM :MC3:/mc_waitq_delete: prompt_wait=13692 prompt_active=9DB0
Sep 13 14:21:04 nt26xx01 814: *Mar 1 03:16:53.941: //-1//DPM :MC3:/du_get_vpPromptName: OK###
Sep 13 14:21:04 nt26xx01 815: *Mar 1 03:16:53.941: $w$pcapp_process()::
Sep 13 14:21:04 nt26xx01 816: *Mar 1 03:16:53.941: $ $pcapp_process() {QUEUE_EVENT}
Sep 13 14:21:04 nt26xx01 817: *Mar 1 03:16:53.941:
Sep 13 14:21:04 nt26xx01 818: *Mar 1 03:16:53.941: $E$pcapp_process() >>pcapp_GetCcEvents()
Sep 13 14:21:04 nt26xx01 819: *Mar 1 03:16:53.945: $ $pcapp_GetCcEvents() HANDOFF >> act_handoff()
Sep 13 14:21:04 nt26xx01 820: *Mar 1 03:16:53.945: prompt and collect app got callID 4
Sep 13 14:21:04 nt26xx01 821: *Mar 1 03:16:53.945: Playing prompt
Sep 13 14:21:04 nt26xx01 822: *Mar 1 03:16:53.945: Prompt interrupt disabled
Sep 13 14:21:04 nt26xx01 823: *Mar 1 03:16:53.945: Return on play complete
Sep 13 14:21:04 nt26xx01 824: *Mar 1 03:16:53.945: Not matching against dial plan
Sep 13 14:21:04 nt26xx01 825: *Mar 1 03:16:53.945: No abort key
Sep 13 14:21:04 nt26xx01 826: *Mar 1 03:16:53.945: No termination key
Sep 13 14:21:04 nt26xx01 827: *Mar 1 03:16:53.945: Matching against 0 patterns.
Sep 13 14:21:04 nt26xx01 828: *Mar 1 03:16:53.949: //-1//MSM :MS4:/ms_create: Iniz ply_timer
Sep 13 14:21:04 nt26xx01 829: *Mar 1 03:16:53.949: $ $pcapp_GetCcEvents() REPORT_DIGITS_DONE >> act_reportDigitsDone()
Sep 13 14:21:04 nt26xx01 830: *Mar 1 03:16:53.949: act_reportDigitsDone callid=4 Enable succeeded.
Sep 13 14:21:04 nt26xx01 831: *Mar 1 03:16:53.949: $ $act_reportDigitsDone() >> ms_play()
Sep 13 14:21:04 nt26xx01 832: *Mar 1 03:16:53.949: //-1//MCM :MR4:/mc_createDynamicReader:
Sep 13 14:21:04 nt26xx01 833: *Mar 1 03:16:53.953: //4//MSM :/ms_associate: packet_size = 160 timestamp increment = 160 packet_duration = 20 C
Sep 13 14:21:04 nt26xx01 834: *Mar 1 03:16:53.953: //4//MSM :/ms_associate: >>ccAssociateStream()
Sep 13 14:21:04 nt26xx01 835: *Mar 1 03:16:53.953: $ $pcapp_GetCcEvents() ##
Sep 13 14:21:04 nt26xx01 836: *Mar 1 03:16:53.953:
Sep 13 14:21:04 nt26xx01 837: *Mar 1 03:16:53.953: $F$pcapp_process() >>pcapp_GetPcappEvents()
Sep 13 14:21:04 nt26xx01 838: *Mar 1 03:16:53.953: $ $pcapp_GetPcappEvents()::>> process_dequeue(app.eventQ)
Sep 13 14:21:04 nt26xx01 839: *Mar 1 03:16:53.953: $ $pcapp_GetPcappEvents() ##
Sep 13 14:21:04 nt26xx01 840: *Mar 1 03:16:53.961: //4//MSM :LP:MS4:/ms_associateDone:
Sep 13 14:21:04 nt26xx01 841: *Mar 1 03:16:53.961: //4//MSM :/ms_asDone_buginf: callID=0x4, pVdb=0x82D0C47C, disposition=0, playFunc=0x811522A
Sep 13 14:21:04 nt26xx01 842: *Mar 1 03:16:53.961: codec=0x5=g711ulaw, vad=0, mediaType=6, streamAssocID=0
Sep 13 14:21:04 nt26xx01 843: *Mar 1 03:16:53.961: //-1//MCM :MR4:/mc_setup_reader_encaps:
Sep 13 14:21:04 nt26xx01 844: *Mar 1 03:16:53.961: //4//MSM :/ms_associateDone: First Buf Play at 00:16:53.926 of ru_no_aaa.au
Sep 13 14:21:04 nt26xx01 845: *Mar 1 03:16:53.961: //4//MSM :/ms_associateDone: 00:16:53.930, Tstart(ply: iSndDly 0)
Sep 13 14:21:04 nt26xx01 846: *Mar 1 03:16:53.965: $w$pcapp_process()::
Sep 13 14:21:04 nt26xx01 847: *Mar 1 03:16:53.965: $ $pcapp_process() {QUEUE_EVENT}
Sep 13 14:21:04 nt26xx01 848: *Mar 1 03:16:53.965:
Sep 13 14:21:04 nt26xx01 849: *Mar 1 03:16:53.969: $E$pcapp_process() >>pcapp_GetCcEvents()
Sep 13 14:21:04 nt26xx01 850: *Mar 1 03:16:53.969: $ $pcapp_GetCcEvents() ##
Sep 13 14:21:04 nt26xx01 851: *Mar 1 03:16:53.969:
Sep 13 14:21:04 nt26xx01 852: *Mar 1 03:16:53.969: $F$pcapp_process() >>pcapp_GetPcappEvents()
подскажите в чем-тут ошибка ? и куда хотя бы копать ? на что в первую очередь
смотреть надо. уже неделю мучаюсь -- голова пухнет.
а пухнет
если нужны еще какието дебуги я предоставлю. главное найти как это решить.