Debugs
Estes são os debugs mais utilizados para tentarmos solucionar os problemas de voz. Pode-se encontrar algumas informações que, associadas aos sintomas do problema, nos levam à solução. Os debugs tem algumas diferenças dependendo das interfaces e sinalizações utilizadas e podem e devem ser utilizados nas três etapas de troubleshooting: Sinalização local, Sinalização da Rede e Chamadas ponto a ponto.
Debug voice ccapi inout
Router# debug voice ccapi inout
voip ccAPI function enter/exit debugging is on
router#
7w6d: cc_api_call_setup_ind (vdbPtr=0x634BFF04,
callInfo={called=17171,called_oct3=0x81,calling=30664001,calling_oct3=0x1,calling_oct3a=0x80,c
alling_xlated=false,subscriber_type_str=Unknown,fdest=1,peer_tag=11,
prog_ind=3,callingIE_present 1},callID=0x632B0AB4) // mostra origem e destino da chamada e o peer de entrada
7w6d: cc_api_call_setup_ind sub_called oct3:len:data=0x0:36:
7w6d: cc_api_call_setup_ind type 11 , prot 0
7w6d: cc_insert_call_entry: Increment call volume counter
7w6d: cc_insert_call_entry: current call volume: 1
7w6d: cc_insert_call_entry: entry’s incoming TRUE. is_incoming is TRUE
7w6d: cc_incr_if_call_volume: not the VoIP or MMoIP
7w6d: cc_process_call_setup_ind (event=0x630823C4)
7w6d: >>>>CCAPI handed cid 1865 with tag 11 to app “DEFAULT”
7w6d: sess_appl: ev(24=CC_EV_CALL_SETUP_IND), cid(1865), disp(0)
7w6d: sess_appl: ev(SSA_EV_CALL_SETUP_IND), cid(1865), disp(0)
7w6d: ssaCallSetupInd
7w6d: ccCallSetContext (callID=0x749, context=0x634F5F84)
7w6d: ssaCallSetupInd cid(1865), st(SSA_CS_MAPPING),oldst(0), ev(24)ev-
>e.evCallSetupInd.nCallInfo.finalDestFlag = 1
7w6d: ssaCallSetupInd finalDest cllng(30664001), clled(17171)
7w6d: ssaCallSetupInd cid(1865), st(SSA_CS_CALL_SETTING),oldst(0),
ev(24)dpMatchPeersMoreArg result= 0
7w6d: ssaSetupPeer cid(1865) peer list: tag(17) called number (17171) //mostra o peer de saída
7w6d: ssaSetupPeer cid(1865), destPat(17171), matched(5), prefix(), peer(63101808), peer-
>encapType (5)
7w6d: ccCallProceeding (callID=0x749, prog_ind=0x0)
7w6d: ccCallSetupRequest (Inbound call = 0x749, outbound peer =17, dest=, params=0x630928C8
mode=0, *callID=0x63092CF8, prog_ind = 3) callingIE_present 1
7w6d: ccCallSetupRequest numbering_type 0x81
7w6d: dest pattern 17171, called 17171, digit_strip 0
7w6d: callingNumber=30664001, calledNumber=17171, redirectNumber= display_info=
calling_oct3a=80
7w6d: accountNumber=, finalDestFlag=1,
guid=db77.16e4.4099.11cc.9b68.bd29.080c.7b2e
7w6d: peer_tag=17
7w6d: ccIFCallSetupRequestPrivate: (vdbPtr=0x63506F5C, dest=,
callParams={called=17171,called_oct3=0x81, calling=30664001,calling_oct3=0x1,
calling_xlated=false, subscriber_type_str=Unknown, fdest=1, voice_peer_tag=17},mode=0x0)
vdbPtr type = 13
7w6d: sub_called oct3:len:data=0x0:36:
7w6d: ccIFCallSetupRequestPrivate: (vdbPtr=0x63506F5C, dest=, callParams={called=17171,
called_oct3 0x81, calling=30664001,calling_oct3 0x1, calling_xlated=false, fdest=1,
voice_peer_tag=17}, mode=0x0, xltrc=-5)
7w6d: sub_called oct3:len:data=0x0:36:
7w6d: cc_insert_call_entry: not incoming entry
7w6d: cc_insert_call_entry: entry’s incoming FALSE. is_incoming is FALSE
7w6d: ccSaveDialpeerTag (callID=0x749, dialpeer_tag=0x11)
7w6d: ccCallSetContext (callID=0x74A, context=0x634F430C)
7w6d: ccCallReportDigits (callID=0x749, enable=0x0)
7w6d: cc_api_call_report_digits_done (vdbPtr=0x634BFF04, callID=0x749, disp=0)
7w6d: sess_appl: ev(52=CC_EV_CALL_REPORT_DIGITS_DONE), cid(1865), disp(0)
7w6d: cid(1865)st(SSA_CS_CALL_SETTING)ev(SSA_EV_CALL_REPORT_DIGITS_DONE)
oldst(SSA_CS_MAPPING)cfid(-1)csize(0)in(1)fDest(1)
7w6d: -cid2(1866)st2(SSA_CS_CALL_SETTING)oldst2(SSA_CS_MAPPING)
7w6d: ssaReportDigitsDone cid(1865) peer list: (empty)
7w6d: ssaReportDigitsDone callid=1865 Reporting disabled.
7w6d: cc_incr_if_call_volume: not the VoIP or MMoIP
7w6d: cc_api_call_proceeding(vdbPtr=0x63506F5C, callID=0x74A,
prog_ind=0x0, rawmsgPtr=0x0)
7w6d: sess_appl: ev(21=CC_EV_CALL_PROCEEDING), cid(1866), disp(0) // está chamando
7w6d: cid(1866)st(SSA_CS_CALL_SETTING)ev(SSA_EV_CALL_PROCEEDING)
oldst(SSA_CS_MAPPING)cfid(-1)csize(0)in(0)fDest(0)
7w6d: -cid2(1865)st2(SSA_CS_CALL_SETTING)oldst2(SSA_CS_CALL_SETTING)
7w6d: ssaCallProc
7w6d: ccGetDialpeerTag (callID=0x749)
7w6d: ssaIgnore cid(1866), st(SSA_CS_CALL_SETTING),oldst(1), ev(21)
7w6d: cc_api_call_cut_progress(vdbPtr=0x63506F5C, callID=0x74A, prog_ind=0x8, sig_ind=0x2)
7w6d: sess_appl: ev(22=CC_EV_CALL_PROGRESS), cid(1866), disp(0)
7w6d: cid(1866)st(SSA_CS_CALL_SETTING)ev(SSA_EV_CALL_PROGRESS)
oldst(SSA_CS_CALL_SETTING)cfid(-1)csize(0)in(0)fDest(0)
7w6d: -cid2(1865)st2(SSA_CS_CALL_SETTING)oldst2(SSA_CS_CALL_SETTING)
7w6d: ssaCutProgress
7w6d: ccGetDialpeerTag (callID=0x749)
7w6d: ccCallCutProgress (callID=0x749, prog_ind=0x8, sig_ind=0x2)
7w6d: ccConferenceCreate (confID=0x63092DA4, callID1=0x749, callID2=0x74A, tag=0x0)
7w6d: cc_api_bridge_done (confID=0x26, srcIF=0x63506F5C, srcCallID=0x74A, dstCallID=0x749,
disposition=0, tag=0x0)
7w6d: cc_api_bridge_done (confID=0x26, srcIF=0x634BFF04, srcCallID=0x749, dstCallID=0x74A,
disposition=0, tag=0x0)
7w6d: cc_api_caps_ind (dstVdbPtr=0x63506F5C, dstCallId=0x74A, srcCallId=0x749,
caps={codec=0x2887F, fax_rate=0xBF, vad=0x3, modem=0x2
codec_bytes=0, signal_type=3})
7w6d: cc_api_caps_ind (Playout: mode 0, initial 60,min 40, max 300)
7w6d: cc_api_cadstCallId=0x749, srcCallId=0x74A,
caps={codec=0x4, fax_rate=0x2, vad=0x2, modem=0x0
codec_bytes=30, siind (Playout: mode 0, in
7w6d: cc_api_caps_ack (dstVdbPt749, srcCallId=0x74A,
vad=0x2, modem=0x0
codec_bytes=30, signal_type=2, seq_num_start=0})
7w6d: sess_appl: ev(29=CC_EV_CONF_CREATE_DONE),
cid(18(SSA_CS_CONFERENCING_PROGRESS)ev(SSA_EV_ALL_SETTING)cfid(38)csize(0)in(1)f
Dest(1)
7w6d: -cid2(1866)st2(SSA_CS_CONFERENCING_PROGRESS)oldst2(SSA_CS_CALL_SETTING)
7w6d: ssaConfCreateDoneAlert
7w6d: cc_process_notify_bridge_done (event=0x630806B4)
7w6d: cc_api_caps_ack (dstVdbPtr=0x63506F5C, dstCallId=0x74A, srcCallId=0x749,
caps={codec=0x4, fax_rate=0x2, vad=0x2, modem=0x0
codec_bytes=30, signal_type=2, seq_num_start=0})
7w6d: cc_api_voice_mode_event , callID=0x749
7w6d: Call Pointer =634F5F84
7w6d: sess_appl: ev(50=CC_EV_VOICE_MODE_DONE), cid(1865), disp(0)
7w6d: cid(1865)st(SSA_CS_CONFERENCED_ALERT)ev(SSA_EV_VOICE_MODE_DONE)
oldst(SSA_CS_CONFERENCING_PROGRESS)cfid(38)csize(0)in(1)fDest(1)
7w6d: -cid2(1866)st2(SSA_CS_CONFERENCED_ALERT)oldst2(SSA_CS_CALL_SETTING)
7w6d: ssaIgnore cid(1865), st(SSA_CS_CONFERENCED_ALERT),oldst(4), ev(50)
7w6d: cc_api_call_connected(vdbPtr=0x63506F5C, callID=0x74A), prog_ind =
0cc_api_call_connected: setting callEntry->connected to TRUE
7w6d: sess_appl: ev(8=CC_EV_CALL_CONNECTED), cid(1866), disp(0) //está falando
7w6d: cid(1866)st(SSA_CS_CONFERENCED_ALERT)ev(SSA_EV_CALL_CONNECTED)
oldst(SSA_CS_CALL_SETTING)cfid(38)csize(0)in(0)fDest(0)
7w6d: –
cid2(1865)st2(SSA_CS_CONFERENCED_ALERT)oldst2(SSA_CS_CONFERENCED_ALERT)
7w6d: ssaConnectAlert
7w6d: ccGetDialpeerTag (callID=0x749)
7w6d: ccCallConnect (callID=0x749), prog_ind = 0ccCallConnect: setting callEntry->connected to TRUE
7w6d: ssaFlushPeerTagQueue cid(1865) peer list: (empty)
7w6d: cc_api_call_disconnected(vdbPtr=0x634BFF04, callID=0x749, cause=0x10)
7w6d: sess_appl: ev(11=CC_EV_CALL_DISCONNECTED), cid(1865), disp(0) // disconectou
7w6d: cid(1865)st(SSA_CS_ACTIVE)ev(SSA_EV_CALL_DISCONNECTED)
oldst(SSA_CS_CONFERENCED_ALERT)cfid(38)csize(0)in(1)fDest(1)
7w6d: -cid2(1866)st2(SSA_CS_ACTIVE)oldst2(SSA_CS_CONFERENCED_ALERT)
7w6d: ssa: Disconnected cid(1865) state(5) cause(0x10)
7w6d: ccConferenceDestroy (confID=0x26, tag=0x0)
7w6d: cc_api_bridge_drop_done (confID=0x26, srcIF=0x63506F5C, srcCallID=0x74A,
dstCallID=0x749, disposition=0 tag=0x0)
7w6d: cc_api_bridge_drop_done (confID=0x26, srcIF=0x634BFF04, srcCallID=0x749,
dstCallID=0x74A, disposition=0 tag=0x0)
7w6d: sess_appl: ev(30=CC_EV_CONF_DESTROY_DONE), cid(1865), disp(0)
7w6d: cid(1865)st(SSA_CS_CONF_DESTROYING)ev(SSA_EV_CONF_DESTROY_DONE)
oldst(SSA_CS_ACTIVE)cfid(-1)csize(0)in(1)fDest(1)
7w6d: -cid2(1866)st2(SSA_CS_CONF_DESTROYING)oldst2(SSA_CS_CONFERENCED_ALERT)
7w6d: ssaConfDestroyDone
7w6d: ccCallDisconnect (callID=0x749, cause=0x10 tag=0x0) //mostra a causa da disconexão
7w6d: cc_api_get_transfer_info: (callID=0x749)
7w6d: ccCallDisconnect (callID=0x74A, cause=0x10 tag=0x0)
7w6d: cc_api_get_transfer_info: (callID=0x74A)
7w6d: cc_decr_if_call_volume: not the VoIP or MMoIP
7w6d: cc_api_call_disconnect_done(vdbPtr=0x634BFF04, callID=0x749, disp=0, tag=0x0)
7w6d: cc_delete_call_entry: Decrement call volume counter
7w6d: cc_delete_call_entry: current call volume: 0
7w6d: cc_delete_call_entry: entry’s incoming TRUE. is_incoming is TRUE
7w6d: sess_appl: ev(12=CC_EV_CALL_DISCONNECT_DONE), cid(1865), disp(0)
7w6d: cid(1865)st(SSA_CS_DISCONNECTING)ev(SSA_EV_CALL_DISCONNECT_DONE)
oldst(SSA_CS_CONF_DESTROYING)cfid(-1)csize(0)in(1)fDest(1)
7w6d: -cid2(1866)st2(SSA_CS_DISCONNECTING)oldst2(SSA_CS_CONFERENCED_ALERT)
7w6d: ssaDisconnectDone
7w6d: cc_decr_if_call_volume: not the VoIP or MMoIP
7w6d: cc_api_call_disconnect_done(vdbPtr=0x63506F5C, callID=0x74A, disp=0, tag=0x0)
7w6d: cc_delete_call_etry
7w6d: cc_delete_call_entry: entry’s_incoming is FALSE
7w6d: sess_appl: ev(12=CC_EV_CALL_DISCONNECT_DONE), cid(1866),
disp(st(SSA_CS_DISCON_DISCONNECT_DONE)
oldst(SSA_CS_CONFERENCED_ALERT)cfid(-1)csize(saDisconnectDone
7w6d: cc_handle_periodic_timer: Calling the callback, ccTimerctx – 0x626C9DE0
7w6d: ccTimerStart: ccTimerctx – 0x626C9DE0
router#
Debug vpm all
Router# debug vpm all
All Voice Port Module debugging is enabled
router#
7w6d: htsp_dsp_message: SEND/RESP_SIG_STATUS: state=0x0 timestamp=65442
systime=480166632
7w6d: htsp_process_event: [1/0:0(25), R2_Q421_IDLE, E_DSP_SIG_0000]
7w6d: r2_q421_ic_seize(1/0:0(25)) Rx SEIZURE //recebeu ocupação
7w6d: r2_reg_start_digit_collection(1/0:0(25))
7w6d: r2_q421_ic_seize(1/0:0(25)) Tx SEIZE ACK (with 100ms delay)[R2 Q.421 1/0:0(25)] set
signal state = 0x8[R2 Q.421 1/0:0(25)] set signal state = 0xC //respondeu a ocupação
7w6d: r2_reg_process_event: [1/0:0(25), R2_REG_IDLE, E_R2_REG_START_COLLECTION(81)]
7w6d: r2_reg_start_collecting(1/0:0(25))
7w6d: r2_reg_timer_stop(1/0:0(25))
7w6d: htsp_process_event: [1/0:0(25), R2_Q421_IC_SEIZE, E_HTSP_SETUP_ACK]
7w6d: r2_q421_ic_setup(1/0:0(25)) E_HTSP_SETUP_ACK
7w6d: r2_reg_offhook(1/0:0(25))
7w6d: r2_reg_process_event: [1/0:0(25), R2_REG_COLLECTING, E_R2_REG_OFFHOOK(82)]
7w6d: r2_reg_ic_offhook(1/0:0(25)) //mudou para OFFHOOK e começa a receber dígitos
7w6d: R2 Incoming Voice(1/0): DSX (E1 1/0:24): STATE: R2_IN_IDLE R2 Got Event R2_START
7w6d: htsp_digit_ready_up(1/0:0(25)): Rx digit=’A’ //recebe dígito de A
7w6d: R2 Incoming Voice(1/0): DSX (E1 1/0:24): STATE: R2_IN_PRE_CALLERID R2 Got Event 11
7w6d: r2_reg_generate_digits(1/0:0(25)): Tx digit ‘1’
7w6d: htsp_digit_ready(1/0:0(25)): Rx digit=’#’
7w6d: R2 Incoming Voice(1/0): DSX (E1 1/0:24): STATE: R2_IN_PRE_CALLERID R2 Got Event
R2_TONE_OFF
7w6d: r2_reg_generate_digits(1/0:0(25)): Tx digit ‘#’
7w6d: htsp_digit_ready_up(1/0:0(25)): Rx digit=’1′
7w6d: R2 Incoming Voice(1/0): DSX (E1 1/0:24): STATE: R2_IN_PRE_CALLERID R2 Got Event 1
7w6d: r2_reg_generate_digits(1/0:0(25)): Tx digit ‘5’
7w6d: htsp_digit_ready(1/0:0(25)): Rx digit=’#’
7w6d: R2 Incoming Voice(1/0): DSX (E1 1/0:24): STATE: R2_IN_CALLERID R2 Got Event
R2_TONE_OFF
7w6d: r2_reg_generate_digits(1/0:0(25)): Tx digit ‘#’
7w6d: htsp_digit_ready_up(1/0:0(25)): Rx digit=’1′
7w6d: R2 Incoming Voice(1/0): DSX (E1 1/0:24): STATE: R2_IN_CALLERID R2 Got Event 1
7w6d: r2_reg_generate_digits(1/0:0(25)): Tx digit ‘5’
7w6d: htsp_digit_ready(1/0:0(25)): Rx digit=’#’
7w6d: R2 Incoming Voice(1/0): DSX (E1 1/0:24): STATE: R2_IN_CALLERID R2 Got Event
R2_TONE_OFF
7w6d: r2_reg_generate_digits(1/0:0(25)): Tx digit ‘#’
7w6d: htsp_digit_ready_up(1/0:0(25)): Rx digit=’3′
7w6d: R2 Incoming Voice(1/0): DSX (E1 1/0:24): STATE: R2_IN_CALLERID R2 Got Event 3
7w6d: r2_reg_generate_digits(1/0:0(25)): Tx digit ‘5’
7w6d: htsp_digit_ready(1/0:0(25)): Rx digit=’#’
7w6d: R2 Incoming Voice(1/0): DSX (E1 1/0:24): STATE: R2_IN_CALLERID R2 Got Event
R2_TONE_OFF
7w6d: r2_reg_generate_digits(1/0:0(25)): Tx digit ‘#’
7w6d: htsp_digit_ready_up(1/0:0(25)): Rx digit=’0′
7w6d: R2 Incoming Voice(1/0): DSX (E1 1/0:24): STATE: R2_IN_CALLERID R2 Got Event 10
7w6d: r2_reg_generate_digits(1/0:0(25)): Tx digit ‘5’
7w6d: htsp_digit_ready(1/0:0(25)): Rx digit=’#’
7w6d: R2 Incoming Voice(1/0): DSX (E1 1/0:24): STATE: R2_IN_CALLERID R2 Got Event
R2_TONE_OFF
7w6d: r2_reg_generate_digits(1/0:0(25)): Tx digit ‘#’
7w6d: htsp_digit_ready_up(1/0:0(25)): Rx digit=’6′
7w6d: R2 Incoming Voice(1/0): DSX (E1 1/0:24): STATE: R2_IN_CALLERID R2 Got Event 6
7w6d: r2_reg_generate_digits(1/0:0(25)): Tx digit ‘5’
7w6d: htsp_digit_ready(1/0:0(25)): Rx digit=’#’
7w6d: R2 Incoming Voice(1/0): DSX (E1 1/0:24): STATE: R2_IN_CALLERID R2 Got Event
R2_TONE_OFF
7w6d: r2_reg_generate_digits(1/0:0(25)): Tx digit ‘#’
7w6d: htsp_digit_ready_up(1/0:0(25)): Rx digit=’6′
7w6d: R2 Incoming Voice(1/0): DSX (E1 1/0:24): STATE: R2_IN_CALLERID R2 Got Event 6
7w6d: r2_reg_generate_digits(1/0:0(25)): Tx digit ‘5’
7w6d: htsp_digit_ready(1/0:0(25)): Rx digit=’#’
7w6d: R2 Incoming Voice(1/0): DSX (E1 1/0:24): STATE: R2_IN_CALLERID R2 Got Event
R2_TONE_OFF
7w6d: r2_reg_generate_digits(1/0:0(25)): Tx digit ‘#’
7w6d: htsp_digit_ready_up(1/0:0(25)): Rx digit=’4′
7w6d: R2 Incoming Voice(1/0): DSX (E1 1/0:24): STATE: R2_IN_CALLERID R2 Got Event 4
7w6d: r2_reg_generate_digits(1/0:0(25)): Tx digit ‘5’
7w6d: htsp_digit_ready(1/0:0(25)): Rx digit=’#’
7w6d: R2 Incoming Voice(1/0): DSX (E1 1/0:24): STATE: R2_IN_CALLERID R2 Got Event
R2_TONE_OFF
7w6d: r2_reg_generate_digits(1/0:0(25)): Tx digit ‘#’
7w6d: htsp_digit_ready_up(1/0:0(25)): Rx digit=’0′
7w6d: R2 Incoming Voice(1/0): DSX (E1 1/0:24): STATE: R2_IN_CALLERID R2 Got Event 10
7w6d: r2_reg_generate_digits(1/0:0(25)): Tx digit ‘5’
7w6d: htsp_digit_ready(1/0:0(25)): Rx digit=’#’
7w6d: R2 Incoming Voice(1/0): DSX (E1 1/0:24): STATE: R2_IN_CALLERID R2 Got Event
R2_TONE_OFF
7w6d: r2_reg_generate_digits(1/0:0(25)): Tx digit ‘#’
7w6d: htsp_digit_ready_up(1/0:0(25)): Rx digit=’0′
7w6d: R2 Incoming Voice(1/0): DSX (E1 1/0:24): STATE: R2_IN_CALLERID R2 Got Event 10
7w6d: r2_reg_generate_digits(1/0:0(25)): Tx digit ‘5’
7w6d: htsp_digit_ready(1/0:0(25)): Rx digit=’#’
7w6d: R2 Incoming Voice(1/0): DSX (E1 1/0:24): STATE: R2_IN_CALLERID R2 Got Event
R2_TONE_OFF
7w6d: r2_reg_generate_digits(1/0:0(25)): Tx digit ‘#’
7w6d: htsp_digit_ready_up(1/0:0(25)): Rx digit=’1′
7w6d: R2 Incoming Voice(1/0): DSX (E1 1/0:24): STATE: R2_IN_CALLERID R2 Got Event 1
7w6d: r2_reg_generate_digits(1/0:0(25)): Tx digit ‘5’
7w6d: htsp_digit_ready(1/0:0(25)): Rx digit=’#’
7w6d: R2 Incoming Voice(1/0): DSX (E1 1/0:24): STATE: R2_IN_CALLERID R2 Got Event
R2_TONE_OFF
7w6d: r2_reg_generate_digits(1/0:0(25)): Tx digit ‘#’ // recebe dígito de B 7w6d: htsp_digit_ready_up(1/0:0(25)): Rx digit=’*’
7w6d: R2 Incoming Voice(1/0): DSX (E1 1/0:24): STATE: R2_IN_CALLERID R2 Got Event 15
7w6d: r2_reg_generate_digits(1/0:0(25)): Tx digit ‘1’
7w6d: htsp_digit_ready(1/0:0(25)): Rx digit=’#’
7w6d: R2 Incoming Voice(1/0): DSX (E1 1/0:24): STATE: R2_IN_COLLECT_DNIS R2 Got Event
R2_TONE_OFF
7w6d: r2_reg_generate_digits(1/0:0(25)): Tx digit ‘#’
7w6d: htsp_digit_ready_up(1/0:0(25)): Rx digit=’7′
7w6d: R2 Incoming Voice(1/0): DSX (E1 1/0:24): STATE: R2_IN_COLLECT_DNIS R2 Got Event 7
7w6d: r2_reg_generate_digits(1/0:0(25)): Tx digit ‘1’
7w6d: htsp_digit_ready(1/0:0(25)): Rx digit=’#’
7w6d: R2 Incoming Voice(1/0): DSX (E1 1/0:24): STATE: R2_IN_COLLECT_DNIS R2 Got Event
R2_TONE_OFF
7w6d: r2_reg_generate_digits(1/0:0(25)): Tx digit ‘#’
7w6d: htsp_digit_ready_up(1/0:0(25)): Rx digit=’1′
7w6d: R2 Incoming Voice(1/0): DSX (E1 1/0:24): STATE: R2_IN_COLLECT_DNIS R2 Got Event 1
7w6d: r2_reg_generate_digits(1/0:0(25)): Tx digit ‘1’
7w6d: htsp_digit_ready(1/0:0(25)): Rx digit=’#’
7w6d: R2 Incoming Voice(1/0): DSX (E1 1/0:24): STATE: R2_IN_COLLECT_DNIS R2 Got Event
R2_TONE_OFF
7w6d: r2_reg_generate_digits(1/0:0(25)): Tx digit ‘#’
7w6d: htsp_digit_ready_up(1/0:0(25)): Rx digit=’7′
7w6d: R2 Incoming Voice(1/0): DSX (E1 1/0:24): STATE: R2_IN_COLLECT_DNIS R2 Got Event 7
7w6d: r2_reg_generate_digits(1/0:0(25)): Tx digit ‘1’
7w6d: htsp_digit_ready(1/0:0(25)): Rx digit=’#’
7w6d: R2 Incoming Voice(1/0): DSX (E1 1/0:24): STATE: R2_IN_COLLECT_DNIS R2 Got Event
R2_TONE_OFF
7w6d: r2_reg_generate_digits(1/0:0(25)): Tx digit ‘#’
7w6d: htsp_digit_ready_up(1/0:0(25)): Rx digit=’1′
7w6d: R2 Incoming Voice(1/0): DSX (E1 1/0:24): STATE: R2_IN_COLLECT_DNIS R2 Got Event 1
7w6d: r2_reg_generate_digits(1/0:0(25)): Tx digit ‘1’
7w6d: htsp_digit_ready(1/0:0(25)): Rx digit=’#’
7w6d: R2 Incoming Voice(1/0): DSX (E1 1/0:24): STATE: R2_IN_COLLECT_DNIS R2 Got Event
R2_TONE_OFF
7w6d: r2_reg_generate_digits(1/0:0(25)): Tx digit ‘#’
7w6d: htsp_dialing_done(1/0:0(25))
7w6d: R2 Incoming Voice(1/0): DSX (E1 1/0:24): STATE: R2_IN_COLLECT_DNIS R2 Got Event
R2_TONE_TIMER
7w6d: r2_reg_generate_digits(1/0:0(25)): Tx digit ‘3#’
7w6d: htsp_digit_ready_up(1/0:0(25)): Rx digit=’1′
7w6d: R2 Incoming Voice(1/0): DSX (E1 1/0:24): STATE: R2_IN_CATEGORY R2 Got Event 1
7w6d: Enter r2_comp_category
7w6d: r2_reg_event_proc(1/0:0(25)) ADDR_INFO_COLLECTED (DNIS=17171, ANI=30664001)
7w6d: r2_reg_process_event: [1/0:0(25), R2_REG_COLLECTING,
E_R2_REG_ADDR_COLLECTED(76)]
7w6d: r2_reg_ic_addr_collected(1/0:0(25))
7w6d: htsp_process_event: [1/0:0(25), R2_Q421_IC_WAIT_ANSWER, E_HTSP_SETUP_ACK]
7w6d: r2_q421_ic_setup_ack(1/0:0(25)) E_HTSP_SETUP_ACK
7w6d: r2_reg_switch(1/0:0(25))
7w6d: r2_reg_process_event: [1/0:0(25), R2_REG_WAIT_FOR_SWITCH,
E_R2_REG_SWITCH(83)]
7w6d: r2_reg_ic_switched(1/0:0(25))
7w6d: htsp_process_event: [1/0:0(25), R2_Q421_IC_WAIT_ANSWER, // esperando resposta
E_HTSP_PROCEEDING]htsp_alert_notify
7w6d: r2_reg_event_proc(1/0:0(25)) ALERTING RECEIVED
7w6d: R2 Incoming Voice(1/0): DSX (E1 1/0:24): STATE: R2_IN_WAIT_REMOTE_ALERT R2 Got
Event R2_ALERTING
7w6d: rx R2_ALERTING in r2_comp_wait_remote_alert
7w6d: r2_reg_generate_digits(1/0:0(25)): Tx digit ‘1’htsp_alert_notify
7w6d: r2_reg_event_proc(1/0:0(25)) ALERTING RECEIVED // chamando
7w6d: R2 Incoming Voice(1/0): DSX (E1 1/0:24): STATE: R2_IN_COMPLETE R2 Got Event
R2_ALERTING
7w6d: htsp_digit_ready_up(1/0:0(25)): Rx digit=’1′
7w6d: R2 Incoming Voice(1/0): DSX (E1 1/0:24): STATE: R2_IN_COMPLETE R2 Got Event 1
7w6d: htsp_digit_ready(1/0:0(25)): Rx digit=’#’
7w6d: R2 Incoming Voice(1/0): DSX (E1 1/0:24): STATE: R2_IN_COMPLETE R2 Got Event
R2_TONE_OFF
7w6d: r2_reg_generate_digits(1/0:0(25)): Tx digit ‘#’
7w6d: htsp_dialing_done(1/0:0(25))
7w6d: R2 Incoming Voice(1/0): DSX (E1 1/0:24): STATE: R2_IN_WAIT_GUARD R2 Got Event
R2_TONE_TIMER
7w6d: R2_IN_CONNECT: call end dial
7w6d: r2_reg_end_dial(1/0:0(25))
7w6d: htsp_process_event: [1/0:0(25), R2_Q421_IC_WAIT_ANSWER,
E_HTSP_VOICE_CUT_THROUGH]htsp_connect: no_offhook 0
7w6d: htsp_process_event: [1/0:0(25), R2_Q421_IC_WAIT_ANSWER, E_HTSP_CONNECT]
7w6d: r2_q421_ic_answer(1/0:0(25)) E_HTSP_CONNECT // conectado, falando
7w6d: r2_q421_ic_answer(1/0:0(25)) Tx ANSWER[R2 Q.421 1/0:0(25)] set signal state = 0x4
7w6d: r2_reg_channel_connected(1/0:0(25))
7w6d: r2_reg_process_event: [1/0:0(25), R2_REG_WAIT_FOR_CONNECT,
E_R2_REG_CONNECT(77)]
7w6d: r2_reg_connect(1/0:0(25))
7w6d: htsp_dsp_message: SEND/RESP_SIG_STATUS: state=0x8 timestamp=20614
systime=480181810
7w6d: htsp_process_event: [1/0:0(25), R2_Q421_IC_ANSWER, E_DSP_SIG_1000]
7w6d: r2_q421_ic_answer_clr_fwd(1/0:0(25)) Rx CLEAR FWD
7w6d: r2_reg_channel_disconnected(1/0:0(25))
7w6d: htsp_timer – 2000 msec
7w6d: r2_reg_process_event: [1/0:0(25), R2_REG_CONNECTED, E_R2_REG_DISCONNECT(78)]
7w6d: r2_reg_disconnect_idle(1/0:0(25)) //disconectado
7w6d: R2 Incoming Voice(1/0): DSX (E1 1/0:24): STATE: R2_IN_IDLE R2 Got Event R2_STOP
7w6d: r2_reg_timer_stop(1/0:0(25))U
7w6d: htsp_process_event: [1/0:0(25), R2_Q421_IC_CLR_FWD, E_HTSP_EVENT_TIMER]
7w6d: htsp_timer_stop
7w6d: r2_reg_channel_disconnected(1/0:0(25))
7w6d: r2_reg_process_event: [1/0:0(25), R2_REG_IDLE, E_R2_REG_DISCONNECT(78)]
7w6d: r2_reg_disconnect_idle(1/0:0(25))
7w6d: R2 Incoming Voice(1/0): DSX (E1 1/0:24): STATE: R2_IN_IDLE R2 Got Event R2_STOP
7w6d: r2_reg_timer_stop(1/0:0(25))htsp_release_req: cause 16, no_onhook 0
7w6d: htsp_process_event: [1/0:0(25), R2_Q421_IDLE, E_HTSP_RELEASE_REQ]
7w6d: r2_q421_idle_release(1/0:0(25)) E_HTSP_RELEASE_REQ
7w6d: r2_q421_idle_release(1/0:0(25)) Tx IDLE[R2 Q.421 1/0:0(25)] set signal state = 0x8
7w6d: htsp_timer_stop
7w6d: r2_reg_channel_disconnected(1/0:0(25))
7w6d: vnm_dsprm_idle_voice_channel:
7w6d: vnm_dsprm_close_cleanup
7w6d: r2_reg_process_event: [1/0:0(25), R2_REG_IDLE, E_R2_REG_DISCONNECT(78)]
7w6d: r2_reg_disconnect_idle(1/0:0(25))
7w6d: R2 Incoming Voice(1/0): DSX (E1 1/0:24): STATE: R2_IN_IDLE R2 Got Event R2_STOP
7w6d: r2_reg_timer_stop(1/0:0(25))ALL //voltou para canal livre.
Debug vtsp all
router# debug vtsp all
Voice telephony call control all debugging is on
router#
7w6d: vtsp_do_call_setup_ind
7w6d: vtsp_allocate_cdb,cdb 0x632B0670
7w6d: vtsp_do_call_setup_ind: Call ID=105322, guid=632B0C30
7w6d: vtsp_do_call_setup_ind: type=0, under_spec=0, name=, id0=0, id1=0, id2=0, calling=, called=
subscriber= callingIE_present 0
7w6d: vtsp_do_call_setup_ind: redirect DN = reason = 0
7w6d: vtsp_insert_cdb,cdb 0x632B0670, CallID=-54
7w6d: vtsp_open_voice_and_set_params
7w6d: vtsp_modem_proto_from_cdb: cap_modem_proto 1073741824playout default
7w6d: vtsp_dsp_echo_canceller_control: echo_cancel: 1vtsp_do_r2_start_digit():
vtsp_dsp_dtmf_mode()
vtsp_do_r2_start_digit(): fsm_push(vtsp_r2_state_table)
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_DSP_DTMF_DIGIT_BEGIN] //recebe primeiro dígito
7w6d: dc_digit_up
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_TSP_R2_DIAL]
7w6d: dc_dial()
vtsp_dial_nopush
7w6d: ds_do_dial: dialing string:1vtsp_dsp_dtmf_dialing: dial_string = 1
7w6d: digit=_, components=2, freq_of_first=1020, freq_of_second=1140, amp_of_first=65386,
amp_of_second=65386
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_DSP_DTMF_DIGIT]
7w6d: dc_digit
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_TSP_R2_DIAL]
7w6d: dc_dial()
vtsp_dial_nopush
7w6d: ds_do_dial: dialing string:#vtsp_dsp_dtmf_dialing: dial_string = #
7w6d: digit=_, components=2, freq_of_first=0, freq_of_second=0, amp_of_first=64636,
amp_of_second=64636
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_DSP_DTMF_DIGIT_BEGIN]
7w6d: dc_digit_up
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_TSP_R2_DIAL]
7w6d: dc_dial()
vtsp_dial_nopush
7w6d: ds_do_dial: dialing string:5vtsp_dsp_dtmf_dialing: dial_string = 5
7w6d: digit=_, components=2, freq_of_first=1020, freq_of_second=780, amp_of_first=65386,
amp_of_second=65386
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_DSP_DTMF_DIGIT] // recebe próximo dígito
7w6d: dc_digit
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_TSP_R2_DIAL]
7w6d: dc_dial()
vtsp_dial_nopush
7w6d: ds_do_dial: dialing string:#vtsp_dsp_dtmf_dialing: dial_string = #
7w6d: digit=_, components=2, freq_of_first=0, freq_of_second=0, amp_of_first=64636,
amp_of_second=64636
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_DSP_DTMF_DIGIT_BEGIN]
7w6d: dc_digit_up
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_TSP_R2_DIAL]
7w6d: dc_dial()
vtsp_dial_nopush
7w6d: ds_do_dial: dialing string:5vtsp_dsp_dtmf_dialing: dial_string = 5
7w6d: digit=_, components=2, freq_of_first=1020, freq_of_second=780, amp_of_first=65386,
amp_of_second=65386
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_DSP_DTMF_DIGIT]
7w6d: dc_digit
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_TSP_R2_DIAL]
7w6d: dc_dial()
vtsp_dial_nopush
7w6d: ds_do_dial: dialing string:#vtsp_dsp_dtmf_dialing: dial_string = #
7w6d: digit=_, components=2, freq_of_first=0, freq_of_second=0, amp_of_first=64636,
amp_of_second=64636
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_DSP_DTMF_DIGIT_BEGIN]
7w6d: dc_digit_up
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_TSP_R2_DIAL]
7w6d: dc_dial()
vtsp_dial_nopush
7w6d: ds_do_dial: dialing string:5vtsp_dsp_dtmf_dialing: dial_string = 5
7w6d: digit=_, components=2, freq_of_first=1020, freq_of_second=780, amp_of_first=65386,
amp_of_second=65386
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_DSP_DTMF_DIGIT]
7w6d: dc_digit
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_TSP_R2_DIAL]
7w6d: dc_dial()
vtsp_dial_nopush
7w6d: ds_do_dial: dialing string:#vtsp_dsp_dtmf_dialing: dial_string = #
7w6d: digit=_, components=2, freq_of_first=0, freq_of_second=0, amp_of_first=64636,
amp_of_second=64636
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_DSP_DTMF_DIGIT_BEGIN]
7w6d: dc_digit_up
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_TSP_R2_DIAL]
7w6d: dc_dial()
vtsp_dial_nopush
7w6d: ds_do_dial: dialing string:5vtsp_dsp_dtmf_dialing: dial_string = 5
7w6d: digit=_, components=2, freq_of_first=1020, freq_of_second=780, amp_of_first=65386,
amp_of_second=65386
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_DSP_DTMF_DIGIT]
7w6d: dc_digit
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_TSP_R2_DIAL]
7w6d: dc_dial()
vtsp_dial_nopush
7w6d: ds_do_dial: dialing string:#vtsp_dsp_dtmf_dialing: dial_string = #
7w6d: digit=_, components=2, freq_of_first=0, freq_of_second=0, amp_of_first=64636,
amp_of_second=64636
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_DSP_DTMF_DIGIT_BEGIN]
7w6d: dc_digit_up
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_TSP_R2_DIAL]
7w6d: dc_dial()
vtsp_dial_nopush
7w6d: ds_do_dial: dialing string:5vtsp_dsp_dtmf_dialing: dial_string = 5
7w6d: digit=_, components=2, freq_of_first=1020, freq_of_second=780, amp_of_first=65386,
amp_of_second=65386
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_DSP_DTMF_DIGIT]
7w6d: dc_digit
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_TSP_R2_DIAL]
7w6d: dc_dial()
vtsp_dial_nopush
7w6d: ds_do_dial: dialing string:#vtsp_dsp_dtmf_dialing: dial_string = #
7w6d: digit=_, components=2, freq_of_first=0, freq_of_second=0, amp_of_first=64636,
amp_of_second=64636
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_DSP_DTMF_DIGIT_BEGIN]
7w6d: dc_digit_up
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_TSP_R2_DIAL]
7w6d: dc_dial()
vtsp_dial_nopush
7w6d: ds_do_dial: dialing string:5vtsp_dsp_dtmf_dialing: dial_string = 5
7w6d: digit=_, components=2, freq_of_first=1020, freq_of_second=780, amp_of_first=65386,
amp_of_second=65386
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_DSP_DTMF_DIGIT]
7w6d: dc_digit
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_TSP_R2_DIAL]
7w6d: dc_dial()
vtsp_dial_nopush
7w6d: ds_do_dial: dialing string:#vtsp_dsp_dtmf_dialing: dial_string = #
7w6d: digit=_, components=2, freq_of_first=0, freq_of_second=0, amp_of_first=64636,
amp_of_second=64636
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_DSP_DTMF_DIGIT_BEGIN]
7w6d: dc_digit_up
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_TSP_R2_DIAL]
7w6d: dc_dial()
vtsp_dial_nopush
7w6d: ds_do_dial: dialing string:5vtsp_dsp_dtmf_dialing: dial_string = 5
7w6d: digit=_, components=2, freq_of_first=1020, freq_of_second=780, amp_of_first=65386,
amp_of_second=65386
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_DSP_DTMF_DIGIT]
7w6d: dc_digit
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_TSP_R2_DIAL]
7w6d: dc_dial()
vtsp_dial_nopush
7w6d: ds_do_dial: dialing string:#vtsp_dsp_dtmf_dialing: dial_string = #
7w6d: digit=_, components=2, freq_of_first=0, freq_of_second=0,mp_of_second=64636
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_DSP_DTMF_DIGIT_BEGIN]
7w6d: dc_digit_up
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_TSP_R2_DIAL]
7w6d: dc_dial()
vtsp_dial_nopush
7w6d: ds_do_dial: dialing string:5vtsp_dsp_dtmf_dialing: dial_string = 5
7w6d: digit=_, components=2, freq_of_first=1020, freq_of_second=780, amp_of_first=65386,
amp_of_second=65386
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_DSP_DTMF_DIGIT]
7w6d: dc_digit
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_TSP_R2_DIAL]
7w6d: dc_dial()
vtsp_dial_nopush
7w6d: ds_do_dial: dialing string:#vtsp_dsp_dtmf_dialing: dial_string = #
7w6d: digit=_, components=2, freq_of_first=0, freq_of_second=0, amp_of_first=64636,
amp_of_second=64636
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_DSP_DTMF_DIGIT_BEGIN]
7w6d: dc_digit_up
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_TSP_R2_DIAL]
7w6d: dc_dial()
vtsp_dial_nopush
7w6d: ds_do_dial: dialing string:5vtsp_dsp_dtmf_dialing: dial_string = 5
7w6d: digit=_, components=2, freq_of_first=1020, freq_of_second=780, amp_of_first=65386,
amp_of_second=65386
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_DSP_DTMF_DIGIT]
7w6d: dc_digit
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_TSP_R2_DIAL]
7w6d: dc_dial()
vtsp_dial_nopush
7w6d: ds_do_dial: dialing string:#vtsp_dsp_dtmf_dialing: dial_string = #
7w6d: digit=_, components=2, freq_of_first=0, freq_of_second=0, amp_of_first=64636,
amp_of_second=64636
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_DSP_DTMF_DIGIT_BEGIN]
7w6d: dc_digit_up
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_TSP_R2_DIAL]
7w6d: dc_dial()
vtsp_dial_nopush
7w6d: ds_do_dial: dialing string:5vtsp_dsp_dtmf_dialing: dial_string = 5
7w6d: digit=_, components=2, freq_of_first=1020, freq_of_second=780, amp_of_first=65386,
amp_of_second=65386
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_DSP_DTMF_DIGIT]
7w6d: dc_digit
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_TSP_R2_DIAL]
7w6d: dc_dial()
vtsp_dial_nopush
7w6d: ds_do_dial: dialing string:#vtsp_dsp_dtmf_dialing: dial_string = #
7w6d: digit=_, components=2, freq_of_first=0, freq_of_second=0, amp_of_first=64636,
amp_of_second=64636
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_DSP_DTMF_DIGIT_BEGIN]
7w6d: dc_digit_up
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_TSP_R2_DIAL]
7w6d: dc_dial()
vtsp_dial_nopush
7w6d: ds_do_dial: dialing string:1vtsp_dsp_dtmf_dialing: dial_string = 1
7w6d: digit=_, components=2, freq_of_first=1020, freq_of_second=1140, amp_of_first=65386,
amp_of_second=65386
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_DSP_DTMF_DIGIT]
7w6d: dc_digit
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_TSP_R2_DIAL]
7w6d: dc_dial()
vtsp_dial_nopush
7w6d: ds_do_dial: dialing string:#vtsp_dsp_dtmf_dialing: dial_string = #
7w6d: digit=_, components=2, freq_of_first=0, freq_of_second=0, amp_of_first=64636,
amp_of_second=64636
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_DSP_DTMF_DIGIT_BEGIN]
7w6d: dc_digit_up
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_TSP_R2_DIAL]
7w6d: dc_dial()
vtsp_dial_nopush
7w6d: ds_do_dial: dialing string:1vtsp_dsp_dtmf_dialing: dial_string = 1
7w6d: digit=_, components=2, freq_of_first=1020, freq_of_second=1140, amp_of_first=65386,
amp_of_second=65386
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_DSP_DTMF_DIGIT]
7w6d: dc_digit
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_TSP_R2_DIAL]
7w6d: dc_dial()
vtsp_dial_nopush
7w6d: ds_do_dial: dialing string:#vtsp_dsp_dtmf_dialing: dial_string = #
7w6d: digit=_, components=2, freq_of_first=0, freq_of_second=0, amp_of_first=64636,
amp_of_second=64636
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_DSP_DTMF_DIGIT_BEGIN]
7w6d: dc_digit_up
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_TSP_R2_DIAL]
7w6d: dc_dial()
vtsp_dial_nopush
7w6d: ds_do_dial: dialing string:1vtsp_dsp_dtmf_dialing: dial_string = 1
7w6d: digit=_, components=2, freq_of_first=1020, freq_of_second=1140, amp_of_first=65386,
amp_of_second=65386
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_DSP_DTMF_DIGIT]
7w6d: dc_digit
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_TSP_R2_DIAL]
7w6d: dc_dial()
vtsp_dial_nopush
7w6d: ds_do_dial: dialing string:#vtsp_dsp_dtmf_dialing: dial_string = #
7w6d: digit=_, components=2, freq_of_first=0, freq_of_second=0, amp_of_first=64636,
amp_of_second=64636
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_DSP_DTMF_DIGIT_BEGIN]
7w6d: dc_digit_up
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_TSP_R2_DIAL]
7w6d: dc_dial()
vtsp_dial_nopush
7w6d: ds_do_dial: dialing string:1vtsp_dsp_dtmf_dialing: dial_string = 1
7w6d: digit=_, components=2, freq_of_first=1020, freq_of_second=1140, amp_of_first=65386,
amp_of_second=65386
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_DSP_DTMF_DIGIT]
7w6d: dc_digit
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_TSP_R2_DIAL]
7w6d: dc_dial()
vtsp_dial_nopush
7w6d: ds_do_dial: dialing string:#vtsp_dsp_dtmf_dialing: dial_string = #
7w6d: digit=_, components=2, freq_of_first=0, freq_of_second=0, amp_of_first=64636,
amp_of_second=64636
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_DSP_DTMF_DIGIT_BEGIN]
7w6d: dc_digit_up
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_TSP_R2_DIAL]
7w6d: dc_dial()
vtsp_dial_nopush
7w6d: ds_do_dial: dialing string:1vtsp_dsp_dtmf_dialing: dial_string = 1
7w6d: digit=_, components=2, freq_of_first=1020, freq_of_second=1140, amp_of_first=65386,
amp_of_second=65386
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_DSP_DTMF_DIGIT]
7w6d: dc_digit
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_TSP_R2_DIAL]
7w6d: dc_dial()
vtsp_dial_nopush
7w6d: ds_do_dial: dialing string:#vtsp_dsp_dtmf_dialing: dial_string = #
7w6d: digit=_, components=2, freq_of_first=0, freq_of_second=0, amp_of_first=64636,
amp_of_second=64636
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_DSP_DIALING_COMPLETE]dc_dialing_done()
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_TSP_R2_DIAL]
7w6d: dc_dial()
vtsp_dial_nopush
7w6d: ds_do_dial: dialing string:3#vtsp_dsp_dtmf_dialing: dial_string = 3#
7w6d: digit=_, components=2, freq_of_first=1020, freq_of_second=900, amp_of_first=65386,
amp_of_second=65386
7w6d: digit=_, components=2, freq_of_first=0, freq_of_second=0, amp_of_first=64636,
amp_of_second=64636
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_DSP_DTMF_DIGIT_BEGIN]
7w6d: dc_digit_up
7w6d: vtsp_tsp_call_switch_ind—CAS call callingnum 30664001 callingIE_present 1
7w6d: vtsp_tsp_call_switch_ind calling_number=30664001 calling_oct3 =
0x1,called_number=17171,called_oct3 = 0x81, subscriber=Unknownoct3a=0x80): peer_tag=11
7w6d: : ev.clg.clir is 0 //número de A e número de B
ev.clg.clid_transparent is
0
ev.clg.null_orig_clg is 0
ev.clg.calling_translated is false
7w6d: vtsp:[1/0:0, S_R2_COLLECT, E_TSP_SWITCH_IND]dc_switch: fsm_pop()
7w6d: vtsp_do_call_setup_ind
7w6d: vtsp_do_call_setup_ind: Call ID=105324, guid=632B0C30
7w6d: vtsp_do_call_setup_ind: type=0, under_spec=0, name=, id0=24, id1=0, id2=25403,
calling=30664001, called=17171 subscriber=Unknown callingIE_present 1
7w6d: vtsp_timer_stop: 480159310
7w6d: vtsp_realloc_cdb,cdb 0x632B0670
7w6d: vtsp_insert_cdb,cdb 0x632B0670, CallID=1867
7w6d: vtsp_open_voice_and_set_params
7w6d: vtsp_modem_proto_from_cdb: cap_modem_proto 1073741824playout default
7w6d: vtsp_dsp_echo_canceller_control: echo_cancel: 1
7w6d: vtsp_save_dialpeer_tag: tag = 17 // dial-peer encontrado
7w6d: vtsp_report_digit_control: enable=0: digit reporting disabled
7w6d: : vtsp_get_digit_timeouts
7w6d: vtsp:[1/0:0:1867, S_SETUP_INDICATED, E_CC_PROCEEDING] //chamando
7w6d: act_proceeding
7w6d: vtsp_get_dialpeer_tag: tag = 17
7w6d: vtsp_get_dialpeer_tag: tag = 17
7w6d: vtsp:[1/0:0:1867, S_PROCEEDING, E_CC_PROGRESS]
7w6d: act_progress
7w6d: vtsp_timer_stop: 480159317
7w6d: vtsp:[1/0:0:1867, S_PROCEEDING, E_CC_BRIDGE]
7w6d: act_bridge
7w6d: vtsp_timer_stop: 480159317
7w6d: vtsp:[1/0:0:1867, S_PROCEEDING, E_TSP_R2_DIAL]vtsp_r2_dial
vtsp_r2_dial(): fsm_push(vtsp_r2_state_table)
7w6d: ds_do_dial: dialing string:1vtsp_dsp_dtmf_dialing: dial_string = 1
7w6d: digit=_, components=2, freq_of_first=1020, freq_of_second=1140, amp_of_first=65386,
amp_of_second=65386
7w6d: vtsp:[1/0:0:1867, S_R2_DIALING, E_CC_CAPS_IND] ds_dialing_default 53
7w6d: vtsp:[1/0:0:1867, S_R2_DIALING, E_CC_CAPS_ACK] ds_dialing_default 54
7w6d: vtsp:[1/0:0:1867, S_R2_DIALING, E_DSP_DTMF_DIGIT_BEGIN]
7w6d: dc_digit_up
7w6d: vtsp:[1/0:0:1867, S_R2_DIALING, E_DSP_DTMF_DIGIT]
7w6d: dc_digit
7w6d: vtsp:[1/0:0:1867, S_R2_DIALING, E_TSP_R2_DIAL]
7w6d: dc_dial()
vtsp_dial_nopush
7w6d: ds_do_dial: dialing string:#vtsp_dsp_dtmf_dialing: dial_string = #
7w6d: digit=_, components=2, freq_of_first=0, freq_of_second=0, amp_of_first=64636,
amp_of_second=64636
7w6d: vtsp:[1/0:0:1867, S_R2_DIALING, E_DSP_DIALING_COMPLETE]dc_dialing_done() //
chamada completa
7w6d: vtsp:[1/0:0:1867, S_R2_DIALING, E_TSP_R2_END_DIAL]ds_end_dial(): fsm_pop()
7w6d: act_caps_ind
7w6d: act_caps_ind:RTP
PT:NTE[0],NSE[0],FaxInd[0],FaxAck[0],CiscoDTMF[0],FaxRelay[0],CASsig[0],ClearChan[0],PCMu[0]
,PCMa[0]
7w6d: act_caps_ind: dtmf relay: mode=1, codec=1
7w6d: act_caps_ind: passthrough: cap_modem_proto 0, cap_modem_codec 0,
cap_modem_redundancy 0, payload 0
7w6d: act_caps_ind:CC_CAP_ENCAP_FRF11 Encap 2, Vad 2, Codec 0x4, CodecBytes 30,
FaxRate 2, FaxBytes 30, FaxNsf 0xAD0051
Sub-channel 30, Bitmask 0x0
SignalType 2, SeqNumStart 0x0
7w6d: act_caps_ind: [ mode:0,init:60, min:40, max:200]
7w6d: act_caps_ack
7w6d: act_caps_ack: TELOGY fax is supported
7w6d: act_caps_ack: passthrough: cap_modem_proto 0, cap_modem_codec 0,
cap_modem_redundancy 0, payload 0
7w6d: act_caps_ack: Named Telephone Event payload 0
7w6d: act_switch_codec: codec = 16
7w6d: vtsp_timer: 480159424
7w6d: vtsp:[1/0:0:1867, SP_PENDING_CODEC_SWITCH, E_DSPRM_PEND_SUCCESS]
7w6d: act_pend_codec_success
7w6d: vtsp_timer_stop: 480159424
7w6d: vtsp_modem_proto_from_cdb: cap_modem_proto 0
7w6d: vtsp_open_voice_and_set_params playout default
7w6d: vtsp_dsp_echo_canceller_control: echo_cancel: 1
7w6d: vtsp_get_dialpeer_tag: tag = 17
7w6d: vtsp:[1/0:0:1867, S_PROCEEDING, E_CC_CONNECT] //falando
7w6d: act_connect
7w6d: vtsp_ring_noan_timer_stop: 480159678
7w6d: vtsp:[1/0:0:1867, S_CONNECT, E_CC_BRIDGE_DROP]
7w6d: act_bdrop
7w6d: vtsp:[1/0:0:1867, S_CONNECT, E_CC_DISCONNECT] // disconectado
7w6d: act_disconnect
7w6d: vtsp_ring_noan_timer_stop: 480163788
7w6d: vtsp_pcm_tone_detect_timer_stop: 480163788
7w6d: vtsp_pcm_switchover_timer_stop: 480163788
7w6d: vtsp_timer_stop: 480163788
7w6d: act_disconnect: cdb 0x632B0670, cause 0x10
7w6d: vtsp_timer: 480163788
7w6d: vtsp:[1/0:0:1867, S_WAIT_STATS, E_DSP_GET_ERROR]
7w6d: act_get_error
7w6d: vtsp_print_error_stats: rx_dropped=0 tx_dropped=0 rx_control=104 tx_control=41
tx_control_dropped=0 dsp_mode_channel_1=0 dsp_mode_channel_2=0 c[0]=0 c[1]=2 c[2]=116
c[3]=91 c[4]=67 c[5]=73 c[6]=116 c[7]=6 c[8]=0 c[9]=22633 c[10]=29807 c[11]=56287 c[12]=62423
c[13]=55273 c[14]=60393 c[15]=60634
7w6d: vtsp_timer_stop: 480163788
7w6d: vtsp_timer: 480163788
7w6d: vtsp:[1/0:0:1867, S_WAIT_STATS, E_DSP_GET_LEVELS]
7w6d: act_get_levels
7w6d: act_stats_complete
7w6d: vtsp_timer_stop: 480163789
7w6d: vtsp_ring_noan_timer_stop: 480163789
7w6d: vtsp_timer: 480163789
7w6d: vtsp:[1/0:0:1867, S_WAIT_RELEASE, E_TSP_DISCONNECT_IND]
7w6d: act_disc_glare_cf_ind
7w6d: vtsp:[1/0:0:1867, S_WAIT_RELEASE, E_TSP_DISCONNECT_CONF]
7w6d: act_wrelease_release
7w6d: vtsp_play_busy_timer_stop: 480163846
7w6d: vtsp_timer_stop: 480163846vtsp_do_call_historyvtsp_do_call_history CoderRate 16
7w6d: vtsp:[1/0:0:1867, S_CLOSE_DSPRM, E_DSPRM_CLOSE_COMPLETE]
7w6d: act_terminate
7w6d: vtsp_free_cdb,cdb 0x632B0670
router#
Debug isdn q931
Router# debug isdn q931
ISDN Q931 packets debugging is on
Router# debug voip ccapi inout
voip ccAPI function enter/exit debugging is on
Router# show debug
ISDN:
ISDN Q931 packets debugging is on
ISDN Q931 packets debug DSLs. (On/Off/No DSL:1/0/-)
DSL 0 –> 31
1 – – – – – – – – – – – – – – – – – – – – – – – – – – – – – – –
voip:
voip ccAPI function enter/exit debugging is on
|– Ação: Roteador recebe uma chamada do PABx para o número “53103” da origem “408”|
*Mar 1 04:51:11.856: ISDN Se1/0:23: RX <- SETUP pd = 8 callref = 0x0001
*Mar 1 04:51:11.860: Bearer Capability i = 0x9090A2
*Mar 1 04:51:11.860: Channel ID i = 0xA98381
*Mar 1 04:51:11.864: Calling Party Number i = 0x0083, ‘408’, Plan:Unknown,
Type:Unknown
*Mar 1 04:51:11.868: Called Party Number i = 0x80, ‘53103’, Plan:Unknown,
Type:Unknown
[cor2]!— Os debugs ISDN Q.931 e Voip ccapi inout mostram o DNIS de 53103 e o
!— ANI (Automatic Number Identification) de 408 envia em plano desconhecido e tipo. [/cor2]
*Mar 1 04:51:11.880: cc_api_call_setup_ind (vdbPtr=0x831721D8, callInfo=
{called=53103,called_oct3=0x80,calling=408,calling_oct3=0x0,
calling_oct3a=0x83, calling_xlated=false,subscriber_type_str=RegularLine,
fdest=1,peer_tag=3, prog_ind=0},callID=0x83349DF8)
*Mar 1 04:51:11.884: cc_API_call_setup_ind type 13 , prot 0
*Mar 1 04:51:11.888: cc_process_call_setup_ind (event=0x83149130)
*Mar 1 04:51:11.888: >>>>CCAPI handed cid 41 with tag 3 to app “DEFAULT”
!— dial-peer POTS 3 foi encontrado como entrada
*Mar 1 04:51:11.888: sess_appl: ev(24=CC_EV_CALL_SETUP_IND), cid(41), disp(0)
*Mar 1 04:51:11.888: sess_appl: ev(SSA_EV_CALL_SETUP_IND), cid(41), disp(0)
*Mar 1 04:51:11.888: ssaCallSetupInd
*Mar 1 04:51:11.892: ccCallSetContext (callID=0x29, context=0x83303C00)
!— A chamada é criada e associada a um de 0x29
*Mar 1 04:51:11.892: ssaCallSetupInd cid(41), st(SSA_CS_MAPPING),oldst(0),
ev(24)ev->e.evCallSetupInd.nCallInfo.finalDestFlag = 1
*Mar 1 04:51:11.892: ssaCallSetupInd finalDest cllng(408), clled(53103)
[cor2]!— A configuração para direct-inward-dial dentro do dial-peer 3, e o DNIS enviado
!— é considerado suficiente para encontrar o outbound dial-peer. [/cor2]
*Mar 1 04:51:11.892: ssaCallSetupInd cid(41), st(SSA_CS_CALL_SETTING),oldst(0),
ev(24)dpMatchPeersMoreArg result= 0
*Mar 1 04:51:11.892: ssaSetupPeer cid(41) peer list: tag(5) called number (53103)
!— Na lista de Dial-peer somente o dial-peer 5 foi encontrado para o DNIS
*Mar 1 04:51:11.892: ssaSetupPeer cid(41), destPat(53103), matched(2),
prefix(), peer(83369DB8), peer->encapType (2)
!— Devido ao destination-pattern tendo 2 digitos e 3 pontos, o match é !— mostrado como 2.
*Mar 1 04:51:11.896: ccCallProceeding (callID=0x29, prog_ind=0x0)
*Mar 1 04:51:11.896: ccCallSetupRequest (Inbound call = 0x29, outbound peer =5,
dest=, params=0x831578C0 mode=0, *callID=0x83157C28, prog_ind = 0)
*Mar 1 04:51:11.896: ccCallSetupRequest numbering_type 0x80
*Mar 1 04:51:11.896: dest pattern 53…, called 53103, digit_strip 0
*Mar 1 04:51:11.896: callingNumber=408, calledNumber=53103, redirectNumber= display_info= calling_oct3a=83
[cor2]!— Apenas antes de encontrar o outbound dial-peer, nós lembramos que temos visto o mesmo ANI
e DNIS no setup ISDN e debug CCAPI inicialmente.
!— Em outras palavras, o roteador não coletou dígitos adicionais depois da ocupação. [/cor2]
*Mar 1 04:51:11.896: accountNumber=, finalDestFlag=1,
guid=c66d.980c.17a8.0051.0000.0000.010a.998a
*Mar 1 04:51:11.896: peer_tag=5
*Mar 1 04:51:11.896: ccIFCallSetupRequestPrivate: (vdbPtr=0x824C6344, dest=,
callParams={called=53103,called_oct3=0x80, calling=408,calling_oct3=0x0,
calling_xlated=false,subscriber_type_str=RegularLine, fdest=1,
voice_peer_tag=5},mode=0x0) vdbPtr type = 3
*Mar 1 04:51:11.900: ccIFCallSetupRequestPrivate: (vdbPtr=0x824C6344, dest=,
callParams={called=53103, called_oct3 0x80, calling=408,calling_oct3 0x0,
calling_xlated=false, fdest=1, voice_peer_tag=5}, mode=0x0, xltrc=-5)
*Mar 1 04:51:11.900: ccSaveDialpeerTag (callID=0x29, dialpeer_tag=
*Mar 1 04:51:11.900: ccCallSetContext (callID=0x2A, context=0x8330408C)
*Mar 1 04:51:11.900: ccCallReportDigits (callID=0x29, enable=0x0)
*Mar 1 04:51:11.904: cc_API_call_report_digits_done (vdbPtr=0x831721D8,
callID=0x29, disp=0)
*Mar 1 04:51:11.904: sess_appl: ev(52=CC_EV_CALL_REPORT_DIGITS_DONE),
cid(41), disp(0)
*Mar 1 04:51:11.904: cid(41)st(SSA_CS_CALL_SETTING)ev
(SSA_EV_CALL_REPORT_DIGITS_DONE)
oldst(SSA_CS_MAPPING)cfid(-1)csize(0)in(1)fDest(1)
.
[cor2]!— saída omitida
.
!— a seguinte saída mostra que a chamada foi finalizada. [/cor2]
*Mar 1 04:51:52.442: ISDN Se1/0:23: RX <- DISCONNECT pd = 8 callref = 0x0001
*Mar 1 04:51:52.442: Cause i = 0x8290 – Normal call clearing
*Mar 1 04:51:52.458: ISDN Se1/0:23: TX -> RELEASE pd = 8 callref = 0x8001
*Mar 1 04:51:52.458: cc_API_call_disconnected(vdbPtr=0x831721D8, callID=0x29, cause=0x10)
*Mar 1 04:51:52.462: sess_appl: ev(11=CC_EV_CALL_DISCONNECTED), cid(41), disp(0)
*Mar 1 04:51:52.462: cid(41)st(SSA_CS_ACTIVE)ev(SSA_EV_CALL_DISCONNECTED)
oldst(SSA_CS_ACTIVE)cfid(9)csize(2)in(1)fDest(1)
*Mar 1 04:51:52.462: -cid2(42)st2(SSA_CS_ACTIVE)oldst2(SSA_CS_ALERT_RCVD)
*Mar 1 04:51:52.462: ssa: Disconnected cid(41) state(5) cause(0x10)
*Mar 1 04:51:52.462: ccConferenceDestroy (confID=0x9, tag=0x0)
*Mar 1 04:51:52.462: cc_API_bridge_drop_done (confID=0x9, srcIF=0x824C6344,
srcCallID=0x2A, dstCallID=0x29, disposition=0 tag=0x0)
*Mar 1 04:51:52.466: cc_API_bridge_drop_done (confID=0x9, srcIF=0x831721D8,
srcCallID=0x29, dstCallID=0x2A, disposition=0 tag=0x0)
*Mar 1 04:51:52.466: sess_appl: ev(30=CC_EV_CONF_DESTROY_DONE), cid(41), disp(0)
*Mar 1 04:51:52.470:
cid(41)st(SSA_CS_CONF_DESTROYING)ev(SSA_EV_CONF_DESTROY_DONE)
oldst(SSA_CS_ACTIVE)cfid(-1)csize(2)in(1)fDest(1)
*Mar 1 04:51:52.470: -cid2(42)st2(SSA_CS_CONF_DESTROYING)oldst2(SSA_CS_ALERT_RCVD)
*Mar 1 04:51:52.470: ssaConfDestroyDone
*Mar 1 04:51:52.470: ccCallDisconnect (callID=0x29, cause=0x10 tag=0x0)
*Mar 1 04:51:52.470: ccCallDisconnect (callID=0x2A, cause=0x10 tag=0x0)
!— Estas linhas acima são usadas para encontrar a causa da disconexão.
*Mar 1 04:51:52.470: ISDN Se1/0:23: RX <- RELEASE_COMP pd = 8 callref = 0x0001
*Mar 1 04:51:52.499: cc_API_call_disconnect_done(vdbPtr=0x831721D8, callID=0x29,
disp=0, tag=0x0)
!— Debug acaba aqui
Estas são as melhores formas de detectar problemas de soluções em VOZ.
Até a próxima!
De 0 a 10, o quanto você recomendaria este artigo para um amigo?