[cisco-voip] Newbe question: GnuGK and Cisco?
Marco Davids (SARA)
marco at sara.nl
Fri Jun 10 18:59:57 EDT 2005
Okay, where shall I begin, being a newbe as I am...
Let's see. Here is what I have and want:
I have:
1 GnuGK running on a Linux-server
1 Gnomemeeting on a Linux-laptop
1 Cisco 7204VXR with two ISDN PRI's from KPN in the Netherlands
I would like to:
- Make phonecalles from my Gnomemeeting to the PSTN and vice versa.
First question: is that possible at all, with the current Cisco hardware?
I managed to register the Cisco to the GnuGK gatekeeper:
!
interface FastEthernet0/0
h323-gateway voip interface
h323-gateway voip id GnuGK ipaddr XXX.XXX.XXX.XXX 1719
h323-gateway voip h323-id CISCO-GW
!
Looking good on both sides.
I configured the Cisco in various ways, not really being sure what I was
doing at all times. At the moment the config is something like this:
!
card type e1 1
!
isdn switch-type primary-net5
!
!
controller E1 1/0
framing NO-CRC4
service-type ccs-voice
pri-group timeslots 1-31
!
interface Serial1/0:15
no ip address
encapsulation hdlc
no logging event link-status
isdn switch-type primary-net5
isdn overlap-receiving
isdn incoming-voice data
isdn calling-number XXXXXXXXX
isdn calling-party-num network-provided
isdn send-alerting
isdn sending-complete
isdn outgoing-voice info-transfer-capability 3.1kHz-audio
no cdp enable
!
voice-port 1/0:15
cptone NL
!
!
dial-peer voice 1 pots
destination-pattern 8.T
direct-inward-dial
port 1/0:15
!
dial-peer voice 2 voip
destination-pattern XXXXXXXXX
session target ras
no vad
!
Debugging on the Cisco:
ISDN events debugging is on
ISDN Q921 packets debugging is on
ISDN Q931 packets debugging is on
CDAPI events debugging is on
H.323 RAS Messages debugging is on
TSP call debugging is on
TSP port debugging is on
TSP error debugging is on
TSP ROSE ASN debugging is on
voip ccAPI function enter/exit debugging is on
CCH323 SPI: H225 State Machine tracing is enabled
CCH323 SPI: H245 State Machine tracing is enabled
CCH323 SPI: RAS State Machine tracing is enabled
CCH323 SPI: Session tracing is enabled
CCH323 SPI: CCH323 Error debug is enabled
CCH323 SPI: CCH323 H450 debug is enabled
The idea is, when I dial H323:812345678900 on GnomeMeeting, the Cisco
dials 12345678900 out the PRI to the PSTN, so the first digit is stripped.
This is what the log in the Cisco shows:
Jun 10 22:37:41.435 UTC: cch323_ct_main: SOCK 0 Event 0x1
Jun 10 22:37:41.435 UTC: cch323_get_new_ccb: ccb (0x62AD6B10) is in use
Jun 10 22:37:41.435 UTC: timer (0x62AD6EB8)starts - delay (15000)
Jun 10 22:37:41.439 UTC: cch323_ct_main: SOCK 2 Event 0x1
Jun 10 22:37:41.439 UTC: [1]towner_data=0x62A5D36C, len=226,
msgPtr=0x622805D0
Jun 10 22:37:41.439 UTC: cch323_gw_process_read_socket: received msg for
H.225
Jun 10 22:37:41.439 UTC: cch323_h225_receiver: received msg of type
SETUPIND_CHOSEN
Jun 10 22:37:41.439 UTC: cch323_h225_receiver CCB existing from TCP accepted
Jun 10 22:37:41.439 UTC: timer(0x62AD6EB8) stops
Jun 10 22:37:41.439 UTC: cch323_h225_receiver Got a new CCB for call id
1655321744
Jun 10 22:37:41.439 UTC: cch323_h225_setup_ind
Jun 10 22:37:41.439 UTC: cch323_h225_setup_ind: callingNumber[XXXXXXXXX]
calledNumber[812345678900]
Jun 10 22:37:41.439 UTC: cch323_h225_setup_ind---- calling IE present
Jun 10 22:37:41.439 UTC: ======= PI in cch323_h225_setup_ind = 0
Jun 10 22:37:41.439 UTC: Receive: infoXCap 8
Jun 10 22:37:41.439 UTC: Receive infoXCap ccb 8
Jun 10 22:37:41.439 UTC: src address = NNN.NNN.NNN.NNN of SETUPIND_CHOSEN
Jun 10 22:37:41.439 UTC: dest address = NNN.NNN.NNN.NNN of SETUPIND_CHOSEN
Jun 10 22:37:41.439 UTC: cch323_run_h225_sm: received event
H225_EVENT_SETUP_IND while at state H225_IDLE
Jun 10 22:37:41.439 UTC: H.225 SM: changing from H225_IDLE state to
H225_WAIT_FOR_ARQ state for callID FFFFFFFF
Jun 10 22:37:41.439 UTC: timer(0x62AD7000) stops
Jun 10 22:37:41.439 UTC: cch323_percall_ras_sm(0x62AD6B10): received
event CCH323_RAS_EVENT_NEWCALL while at CCH323_RAS_STATE_IDLE state
cch323_ras_send_arq: called
Jun 10 22:37:41.443 UTC: Not using Voice Class Codec
Jun 10 22:37:41.443 UTC: cch323_set_peer: peer: 629432A8,
peer->voice_peer_tag: 2, ccb: 62AD6B10h323chan_dgram_send:Sent UDP msg.
Bytes sent: 150 to NNN.NNN.NNN.NNN:1719
Jun 10 22:37:41.443 UTC: RASLib::GW_RASSendARQ: ARQ (seq# 33858) sent to
NNN.NNN.NNN.NNN
Jun 10 22:37:41.443 UTC: timer (0x62AD7000)starts - delay (3000)
Jun 10 22:37:41.443 UTC: cch323_percall_ras_sm(0x62AD6B10): changing to
new state CCH323_RAS_STATE_ARQ
Jun 10 22:37:41.463 UTC: cch323_ct_main: SOCK 1 Event 0x1
Jun 10 22:37:41.463 UTC: h323chan_dgram_recvdata:rcvd from
[NNN.NNN.NNN.NNN:1719] on sock[1]
Jun 10 22:37:41.463 UTC: [1]towner_data=0x61D817BC, len=33,
msgPtr=0x6288A970
Jun 10 22:37:41.463 UTC: cch323_gw_process_read_socket: received msg for RAS
Jun 10 22:37:41.463 UTC: ACF (seq# 33858) rcvd
Jun 10 22:37:41.463 UTC: cch323_ras_handle_recv_msg: received msg of
type ACF_CHOSEN
cch323_ras_rcv_acf:called
Jun 10 22:37:41.463 UTC: current active call count is 1
Jun 10 22:37:41.463 UTC: timer(0x62AD7000) stops
Jun 10 22:37:41.463 UTC: cch323_percall_ras_sm(0x62AD6B10): received
event CCH323_RAS_EVENT_ACF while at CCH323_RAS_STATE_ARQ state
Jun 10 22:37:41.463 UTC: timer (0x62AD7020)starts - delay
(120000)cch323_ras_acf_notify:called
Jun 10 22:37:41.463 UTC: H.225 SM: process event H225_EVENT_RAS_SUCCESS,
for callID FFFFFFFF
Jun 10 22:37:41.463 UTC: cch323_run_h225_sm: received event
H225_EVENT_RAS_SUCCESS while at state H225_WAIT_FOR_ARQ
Jun 10 22:37:41.467 UTC: H.225 SM: changing from H225_WAIT_FOR_ARQ state
to H225_SETUP state for callID FFFFFFFF
Jun 10 22:37:41.467 UTC: Not using Voice Class Codec
Jun 10 22:37:41.467 UTC: cch323_set_peer: peer: 629432A8,
peer->voice_peer_tag: 2, ccb: 62AD6B10
Jun 10 22:37:41.467 UTC: Changing to new event H245_LISTEN_REQ_EVENT
Jun 10 22:37:41.467 UTC: cch323_h245_connection_sm:H245_LISTEN: received
event H245_LISTEN_REQ_EVENT while at H245_NONE state
changing from H245_NONE state to H245_WAITING state
Jun 10 22:37:41.467 UTC: cch323_create_incoming_callinfo_block: peer
61BC9434, (*peer)->voice_peer_tag 2, ccb: 62AD6B10
Jun 10 22:37:41.467 UTC: cc_api_call_setup_ind (vdbPtr=0x62349310,
callInfo={called=812345678900,called_oct3=0x81,calling=204685925,calling_oct3=0x81,calling_oct3a=0x0,calling_xlated=false,subscriber_type_str=Unknown,fdest=1,peer_tag=2,
prog_ind=0,callingIE_present 1},callID=0x62AD6B84)
Jun 10 22:37:41.467 UTC: cc_api_call_setup_ind type 0 , prot 1
Jun 10 22:37:41.467 UTC: cc_api_call_setup_ind (vdbPtr=0x62349310,
callInfo={called=812345678900, calling=204685925, fdest=1 peer_tag=2},
callID=0x62AD6B84)
Jun 10 22:37:41.467 UTC: Playout Mode: 1,Init 60, Min 40, Max 200
Jun 10 22:37:41.467 UTC: Not using Voice Class Codec
Jun 10 22:37:41.467 UTC: cch323_set_peer: peer: 629432A8,
peer->voice_peer_tag: 2, ccb: 62AD6B10
Jun 10 22:37:41.467 UTC: cch323_percall_ras_sm(0x62AD6B10): changing to
new state CCH323_RAS_STATE_ACTIVE
Jun 10 22:37:41.467 UTC: cc_process_call_setup_ind (event=0x626EDB2C)
Jun 10 22:37:41.467 UTC: >>>>CCAPI handed cid 61 with tag 2 to app "DEFAULT"
Jun 10 22:37:41.467 UTC: sess_appl: ev(24=CC_EV_CALL_SETUP_IND),
cid(61), disp(0)
Jun 10 22:37:41.467 UTC: sess_appl: ev(SSA_EV_CALL_SETUP_IND), cid(61),
disp(0)
Jun 10 22:37:41.467 UTC: ssaCallSetupInd
Jun 10 22:37:41.467 UTC: ccCallSetContext (callID=0x3D, context=0x62A88CBC)
Jun 10 22:37:41.467 UTC: ssaCallSetupInd cid(61),
st(SSA_CS_MAPPING),oldst(0),
ev(24)ev->e.evCallSetupInd.nCallInfo.finalDestFlag = 1
Jun 10 22:37:41.467 UTC: ssaCallSetupInd finalDest cllng(XXXXXXXXX),
clled(812345678900)
Jun 10 22:37:41.467 UTC: ssaCallSetupInd cid(61),
st(SSA_CS_CALL_SETTING),oldst(0), ev(24)dpMatchPeersMoreArg result= 0
Jun 10 22:37:41.467 UTC: ssaSetupPeer cid(61) peer list: tag(1) called
number (812345678900) tag(3) called number (812345678900)
Jun 10 22:37:41.467 UTC: ssaSetupPeer cid(61), destPat(812345678900),
matched(1), prefix(), peer(62941698), peer->encapType (1)
Jun 10 22:37:41.467 UTC: ccCallProceeding (callID=0x3D, prog_ind=0x0)
Jun 10 22:37:41.467 UTC: ccCallSetupRequest (Inbound call = 0x3D,
outbound peer =1, dest=, params=0x626F4778 mode=0, *callID=0x626F4AE8,
prog_ind = 0) callingIE_present 1
Jun 10 22:37:41.467 UTC: ccCallSetupRequest numbering_type 0x81
Jun 10 22:37:41.467 UTC: ccCallSetupRequest encapType 1
clid_restrict_disable 1 null_orig_clg 0 clid_transparent 0 callingNumber
XXXXXXXXX
Jun 10 22:37:41.467 UTC: dest pattern 8.T, called 812345678900,
digit_strip 1
Jun 10 22:37:41.467 UTC: callingNumber=XXXXXXXXX,
calledNumber=812345678900, redirectNumber= display_info=Marco Davids
calling_oct3a=0
Jun 10 22:37:41.467 UTC: accountNumber=, finalDestFlag=1,
guid=8a64.67ec.6dd8.d911.8b3f.0002.2d02.88ed
Jun 10 22:37:41.467 UTC: peer_tag=1
Jun 10 22:37:41.467 UTC: ccIFCallSetupRequestPrivate:
(vdbPtr=0x62714070, dest=,
callParams={called=812345678900,called_oct3=0x81,
calling=XXXXXXXXX,calling_oct3=0x81, calling_xlated=false,
subscriber_type_str=Unknown, fdest=1, voice_peer_tag=1},mode=0x0) vdbPtr
type = 6
Jun 10 22:37:41.467 UTC: ccIFCallSetupRequestPrivate:
(vdbPtr=0x62714070, dest=, callParams={called=812345678900, called_oct3
0x81, calling=XXXXXXXXX,calling_oct3 0x81, calling_xlated=false,
fdest=1, voice_peer_tag=1}, mode=0x0, xltrc=-5)
Jun 10 22:37:41.467 UTC: ccSaveDialpeerTag (callID=0x3D, dialpeer_tag=0x1)
Jun 10 22:37:41.467 UTC: cch323_do_set_dialpeer_tag: gw_id=1, callID=61
Jun 10 22:37:41.467 UTC: ccCallSetContext (callID=0x3E, context=0x62A8916C)
Jun 10 22:37:41.467 UTC: ccCallReportDigits (callID=0x3D, enable=0x0)
Jun 10 22:37:41.467 UTC: cch323_report_digit_control: enable=0: disabled.
Jun 10 22:37:41.467 UTC: cc_api_call_report_digits_done
(vdbPtr=0x62349310, callID=0x3D, disp=0)
Jun 10 22:37:41.471 UTC: sess_appl:
ev(53=CC_EV_CALL_REPORT_DIGITS_DONE), cid(61), disp(0)
Jun 10 22:37:41.471 UTC:
cid(61)st(SSA_CS_CALL_SETTING)ev(SSA_EV_CALL_REPORT_DIGITS_DONE)
oldst(SSA_CS_MAPPING)cfid(-1)csize(0)in(1)fDest(1)
Jun 10 22:37:41.471 UTC:
-cid2(62)st2(SSA_CS_CALL_SETTING)oldst2(SSA_CS_MAPPING)
Jun 10 22:37:41.471 UTC: ssaReportDigitsDone cid(61) peer list: tag(3)
called number (812345678900)
Jun 10 22:37:41.471 UTC: ssaReportDigitsDone callid=61 Reporting disabled.
Jun 10 22:37:41.471 UTC: ISDN Se1/0:15: Outgoing call id = 0x8014, dsl 0
Jun 10 22:37:41.471 UTC: tsp_setup_req-------- callingIE_present 1
Jun 10 22:37:41.471 UTC: tsp_setup_req calling 0ct3 0x81, called oct3 0x81,
oct3a 0x0
Jun 10 22:37:41.471 UTC: sub_calling oct3:len:data=0x0:0:,
Jun 10 22:37:41.471 UTC: sub_called oct3:len:data=0x0:0:
Jun 10 22:37:41.471 UTC: display_info: Marco Davids
Jun 10 22:37:41.471 UTC: tsp_cdapi_form_msg: type 2 tsp_cdb->prog_ind 0
Jun 10 22:37:41.471 UTC: CDAPI Se1/0:15: TX -> CDAPI_MSG_CONNECT_REQ to
ISDN call = 0x8014
Jun 10 22:37:41.471 UTC: From Appl/Stack = TSP CDAPI Application
Voice
Jun 10 22:37:41.471 UTC: Call Type = VOICE
Jun 10 22:37:41.471 UTC: B Channel = -1
Jun 10 22:37:41.471 UTC: Cause = 0
Jun 10 22:37:41.471 UTC: Calling Party Number = XXXXXXXXX
Jun 10 22:37:41.471 UTC: Called Party Number = 12345678900
Jun 10 22:37:41.471 UTC: CDAPI-ISDN Se1/0:15: RX <-
CDAPI_MSG_CONNECT_REQ from TSP CDAPI Application Voice call = 0x8014
Jun 10 22:37:41.471 UTC: Call Type = VOICE
Jun 10 22:37:41.471 UTC: B Channel = -1
Jun 10 22:37:41.471 UTC: Cause = 0
Jun 10 22:37:41.471 UTC: Calling Party Number = XXXXXXXXX
Jun 10 22:37:41.471 UTC: Called Party Number = 12345678900
Jun 10 22:37:41.471 UTC: ISDN Se1/0:15: process_pri_call(): call id
0x8014, number 12345678900, speed 0, call type VOICE, redialed? f, csm
call? f, pdata? t
Jun 10 22:37:41.471 UTC: callER type/plan overridden by call_decode
Jun 10 22:37:41.471 UTC: did't copy oct3a reason: no octet 3a
Jun 10 22:37:41.471 UTC: callED type/plan overridden by call_decode
Jun 10 22:37:41.471 UTC: did't copy oct3a reason: not CALLER_NUMBER_IE
Jun 10 22:37:41.471 UTC: building outgoing channel id for call nfas_int
is 0 len is 0
Jun 10 22:37:41.471 UTC: ISDN Se1/0:15: TX -> INFOc sapi=0 tei=0 ns=57
nr=58
i=0x0802001A05A104038890A31803A9839F6C0A81323034363835393235700C813132333435363738393030
Jun 10 22:37:41.475 UTC: SETUP pd = 8 callref = 0x001A
Jun 10 22:37:41.475 UTC: Sending Complete
Jun 10 22:37:41.475 UTC: Bearer Capability i = 0x8890A3
Jun 10 22:37:41.475 UTC: Channel ID i = 0xA9839F
Jun 10 22:37:41.475 UTC: Calling Party Number i = 0x81,
'XXXXXXXXX', Plan:ISDN, Type:Unknown
Jun 10 22:37:41.475 UTC: Called Party Number i = 0x81,
'12345678900', Plan:ISDN, Type:Unknown
Jun 10 22:37:41.475 UTC: cch323_do_call_proceeding: gw_id=1, callID=61
Jun 10 22:37:41.475 UTC: H.225 SM: process event H225_EVENT_CALLPROC,
for callID 3D
Jun 10 22:37:41.475 UTC: cch323_run_h225_sm: received event
H225_EVENT_CALLPROC while at state H225_SETUP
Jun 10 22:37:41.475 UTC: H.225 SM: changing from H225_SETUP state to
H225_CALLPROC state for callID 3D
Jun 10 22:37:41.475 UTC: ======= PI in
cch323_h225_generic_send_callproc = 0
Jun 10 22:37:41.487 UTC: ISDN Se1/0:15: RX <- RRr sapi=0 tei=0 nr=58
Jun 10 22:37:41.563 UTC: ISDN Se1/0:15: RX <- INFOc sapi=0 tei=0 ns=58
nr=58 i=0x0802801A5A08028281
Jun 10 22:37:41.563 UTC: RELEASE_COMP pd = 8 callref = 0x801A
Jun 10 22:37:41.563 UTC: Cause i = 0x8281 -
Unallocated/unassigned number
Jun 10 22:37:41.563 UTC: ISDN Se1/0:15: TX -> RRr sapi=0 tei=0 nr=59
Jun 10 22:37:41.563 UTC: ISDN Se1/0:15: CCPRI_ReleaseCall(): bchan 31,
call id 0x8014, call type VOICE
Jun 10 22:37:41.563 UTC: CCPRI_ReleaseChan released b_dsl 0 B_Chan 31
Jun 10 22:37:41.563 UTC: ISDN Se1/0:15: LIF_EVENT: ces/callid 1/0x8014
CALL_CLEARED
Jun 10 22:37:41.563 UTC: ISDN Se1/0:15: received CALL_CLEARED call_id
0x8014
Jun 10 22:37:41.563 UTC: CDAPI Se1/0:15: TX ->
CDAPI_MSG_SUBTYPE_REL_COMP_IND to TSP CDAPI Application Voice call = 0x8014
Jun 10 22:37:41.563 UTC: From Appl/Stack = ISDN
Jun 10 22:37:41.563 UTC: Call Type = VOICE
Jun 10 22:37:41.563 UTC: B Channel = 65535
Jun 10 22:37:41.563 UTC: Cause = 1
Jun 10 22:37:41.563 UTC: CDAPI TSP RX ===> callId=(8014), MsgType=(9 )
Sub=(14)
Jun 10 22:37:41.563 UTC: cdapi_tsp_rcv_msg: msgType 9 msgSubtype =
14cdapi_tsp_info_ind
Jun 10 22:37:41.563 UTC: tsp_cdapi_msg_free returns 1
Jun 10 22:37:41.563 UTC: ISDN Se1/0:15: LIF_EVENT: ces/callid 1/0x0
CALL_REJECTION
Jun 10 22:37:41.563 UTC: tsp_process_event: [1/0:15, S_TSP_OUTCALL,
E_CDAPI_TSP_RELEASE_COMP_IND] cdapi_tsp_release_ind
Jun 10 22:37:41.563 UTC: Raw Message MaMa is TSP owner is TSP, length is
4, ptr is 626F0630, type is 0, protocol id is 1
Jun 10 22:37:41.563 UTC: Raw Message is : 08 02 82 81
Jun 10 22:37:41.567 UTC: cc_api_call_disconnected(vdbPtr=0x62714070,
callID=0x3E, cause=0x1)
Jun 10 22:37:41.567 UTC: sess_appl: ev(11=CC_EV_CALL_DISCONNECTED),
cid(62), disp(0)
Jun 10 22:37:41.567 UTC:
cid(62)st(SSA_CS_CALL_SETTING)ev(SSA_EV_CALL_DISCONNECTED)
oldst(SSA_CS_MAPPING)cfid(-1)csize(0)in(0)fDest(0)
Jun 10 22:37:41.567 UTC:
-cid2(61)st2(SSA_CS_CALL_SETTING)oldst2(SSA_CS_CALL_SETTING)
Jun 10 22:37:41.567 UTC: ssaDiscSetting
Jun 10 22:37:41.567 UTC: ccCallDisconnect (callID=0x3E, cause=0x1 tag=0x0)
Jun 10 22:37:41.567 UTC: ccCallDisconnect: existing_cause = 0x0,
new_cause = 0x1
Jun 10 22:37:41.567 UTC: ssaDiscSetting: Rotary Retry cid(61) peer
list: tag(3) called number (812345678900)
Jun 10 22:37:41.567 UTC: ssaSetupPeer cid(61) peer list: tag(3) called
number (812345678900)
Jun 10 22:37:41.567 UTC: ssaSetupPeer cid(61), destPat(812345678900),
matched(0), prefix(), peer(62ADAC78), peer->encapType (2)
Jun 10 22:37:41.567 UTC: ssaSetupPeer cid(61), can't gateway with peer
tag(3))
Jun 10 22:37:41.567 UTC: ccCallDisconnect (callID=0x3D, cause=0x1 tag=0x0)
Jun 10 22:37:41.567 UTC: ccCallDisconnect: existing_cause = 0x0,
new_cause = 0x1
Jun 10 22:37:41.567 UTC: ccCallReportDigits (callID=0x3D, enable=0x0)
Jun 10 22:37:41.567 UTC: cch323_report_digit_control: enable=0: disabled.
Jun 10 22:37:41.567 UTC: cc_api_call_report_digits_done
(vdbPtr=0x62349310, callID=0x3D, disp=0)
Jun 10 22:37:41.567 UTC: sess_appl:
ev(53=CC_EV_CALL_REPORT_DIGITS_DONE), cid(61), disp(0)
Jun 10 22:37:41.567 UTC:
cid(61)st(SSA_CS_DISCONNECTING)ev(SSA_EV_CALL_REPORT_DIGITS_DONE)
oldst(SSA_CS_CALL_SETTING)cfid(-1)csize(0)in(1)fDest(1)
Jun 10 22:37:41.567 UTC: ssaReportDigitsDone cid(61) peer list: (empty)
Jun 10 22:37:41.567 UTC: ssaReportDigitsDone callid=61 Reporting disabled.
Jun 10 22:37:41.567 UTC: cch323_ct_main: SOCK 3 Event 0x1
cch323_h245_channel_established_ind: using fd=4 to send msgs
Jun 10 22:37:41.567 UTC: Changing to new event H245_ESTABLISHED_EVENT
Jun 10 22:37:41.567 UTC: cch323_h245_connection_sm:H245_LISTEN: received
event H245_ESTABLISHED_EVENT while at H245_WAITING state
Jun 10 22:37:41.567 UTC: timer(0x62AD7090) stopsSet new event
H245_EVENT_CAP_REQ, for callID 3D
Jun 10 22:37:41.567 UTC: cch323_run_h245_cap_out_sm: received event
H245_EVENT_CAP_REQ while at state H245_CAP_NONE
Jun 10 22:37:41.567 UTC: Using DP configured Codecs
Jun 10 22:37:41.567 UTC: Near-end Pref Codecs = G.729 IETF
Jun 10 22:37:41.567 UTC: send_caps_request: included rtp in caps table
Jun 10 22:37:41.567 UTC: send_caps_request: included signal in caps table
Jun 10 22:37:41.567 UTC: send_caps_request: included alpha in caps table
Jun 10 22:37:41.567 UTC: send_caps_request: included hookflash in caps table
Jun 10 22:37:41.571 UTC: timer (0x62AD70D0)starts - delay (15000)
Jun 10 22:37:41.571 UTC: changing from H245_CAP_NONE state to
H245_CAP_WAIT state
Jun 10 22:37:41.571 UTC: Changing to new event H245_EVENT_MSD, for callID 3D
Jun 10 22:37:41.571 UTC: cch323_run_h245_ms_sm: received event
H245_EVENT_MSD while at state H245_MS_NONE
Jun 10 22:37:41.571 UTC: changing from H245_MS_NONE state to
H245_MS_OUTGOING_WAIT state
Jun 10 22:37:41.571 UTC: timer (0x62AD70B0)starts - delay
(15000)cch323_run_h245_ms_sm: Sent MSD Request
changing from H245_WAITING state to H245_CONNECTED
statecch323_do_call_disconnect: gw_id=1, callID=61
Jun 10 22:37:41.571 UTC: H.225 SM: process event H225_EVENT_RELEASE, for
callID 3D
Jun 10 22:37:41.571 UTC: cch323_run_h225_sm: received event
H225_EVENT_RELEASE while at state H225_CALLPROC
Jun 10 22:37:41.571 UTC: H.225 SM: changing from H225_CALLPROC state to
H225_WAIT_FOR_DRQ state for callID 3D
Jun 10 22:37:41.571 UTC: src address = NNN.NNN.NNN.NNN of
h225TerminateRequest
Jun 10 22:37:41.571 UTC: dest address = NNN.NNN.NNN.NNN of
h225TerminateRequest
Jun 10 22:37:41.571 UTC: timer (0x62AD6ED8)starts - delay (2000)
Jun 10 22:37:41.571 UTC: timer(0x62AD7000) stops
Jun 10 22:37:41.571 UTC: cch323_percall_ras_sm(0x62AD6B10): received
event CCH323_RAS_EVENT_CALLDISC while at CCH323_RAS_STATE_ACTIVE state
Jun 10 22:37:41.571 UTC: timer(0x62AD7020) stopsh323chan_dgram_send:Sent
UDP msg. Bytes sent: 62 to NNN.NNN.NNN.NNN:1719
Jun 10 22:37:41.571 UTC: RASLib::GW_RASSendDRQ: DRQ (seq# 33859) sent to
NNN.NNN.NNN.NNN
Jun 10 22:37:41.571 UTC: timer (0x62AD7000)starts - delay (3000)
Jun 10 22:37:41.571 UTC: cch323_percall_ras_sm(0x62AD6B10): changing to
new state CCH323_RAS_STATE_DRQ
Jun 10 22:37:41.571 UTC: Call Active Playout Mode: 1,Init 60, Min 40,
Max 200
Jun 10 22:37:41.571 UTC: Call History Playout Mode: 1,Init 60, Min 40,
Max 200
Jun 10 22:37:41.571 UTC: cc_api_icpif: expect factor = 0
Jun 10 22:37:41.571 UTC: tsp_process_event: [1/0:15, S_TSP_WAIT_RELEASE,
E_TSP_RELEASE_REQ] cdapi_tsp_release_comp
Jun 10 22:37:41.571 UTC: cc_api_call_disconnect_done(vdbPtr=0x62714070,
callID=0x3E, disp=0, tag=0x0)
Jun 10 22:37:41.571 UTC: sess_appl: ev(12=CC_EV_CALL_DISCONNECT_DONE),
cid(62), disp(0)
Jun 10 22:37:41.571 UTC:
cid(62)st(SSA_CS_DISCONNECTING)ev(SSA_EV_CALL_DISCONNECT_DONE)
oldst(SSA_CS_CALL_SETTING)cfid(-1)csize(0)in(0)fDest(0)
Jun 10 22:37:41.571 UTC: ssaDisconnectDone
Jun 10 22:37:41.599 UTC: cch323_ct_main: SOCK 1 Event 0x1
Jun 10 22:37:41.599 UTC: h323chan_dgram_recvdata:rcvd from
[NNN.NNN.NNN.NNN:1719] on sock[1]
Jun 10 22:37:41.599 UTC: [1]towner_data=0x61D817BC, len=3,
msgPtr=0x6288D564
Jun 10 22:37:41.599 UTC: cch323_gw_process_read_socket: received msg for RAS
Jun 10 22:37:41.599 UTC: DCF (seq# 33859) rcvd
Jun 10 22:37:41.603 UTC: cch323_ras_handle_recv_msg: received msg of
type DCF_CHOSEN
Jun 10 22:37:41.603 UTC: cch323_ras_rcv_dcf: current active call count is 0
Jun 10 22:37:41.603 UTC: timer(0x62AD7000) stops
Jun 10 22:37:41.603 UTC: cch323_percall_ras_sm(0x62AD6B10): received
event CCH323_RAS_EVENT_DCF while at CCH323_RAS_STATE_DRQ state
Jun 10 22:37:41.603 UTC: H.225 SM: process event H225_EVENT_RAS_SUCCESS,
for callID 3D
Jun 10 22:37:41.603 UTC: cch323_run_h225_sm: received event
H225_EVENT_RAS_SUCCESS while at state H225_WAIT_FOR_DRQ
Jun 10 22:37:41.603 UTC: H.225 SM: changing from H225_WAIT_FOR_DRQ state
to H225_WAIT_REL_COMP state for callID 3D
Jun 10 22:37:41.603 UTC: cch323_percall_ras_sm(0x62AD6B10): changing to
new state CCH323_RAS_STATE_IDLE
Jun 10 22:37:41.603 UTC: cch323_ct_main: SOCK 2 Event 0x1
Jun 10 22:37:41.603 UTC: [1]towner_data=0x62A5D36C, len=48,
msgPtr=0x62A43750
Jun 10 22:37:41.603 UTC: cch323_gw_process_read_socket: received msg for
H.225
Jun 10 22:37:41.603 UTC: cch323_h225_receiver: received msg of type
RELEASEIND_CHOSEN
Jun 10 22:37:41.603 UTC: timer(0x62AD6EB8) stops
Jun 10 22:37:41.603 UTC: src address = NNN.NNN.NNN.NNN of RELEASEIND_CHOSEN
Jun 10 22:37:41.607 UTC: dest address = NNN.NNN.NNN.NNN of RELEASEIND_CHOSEN
Jun 10 22:37:41.607 UTC: cch323_run_h225_sm: received event
H225_EVENT_RELEASE_IND while at state H225_WAIT_REL_COMP
Jun 10 22:37:41.607 UTC: timer(0x62AD6ED8) stops
Jun 10 22:37:41.607 UTC: H.225 SM: changing from H225_WAIT_REL_COMP
state to H225_IDLE state for callID 3D
cch323_call_generic_cleanup: for callID 3D disconnected flag 1
Jun 10 22:37:41.607 UTC: timer(0x62AD7090) stops
Jun 10 22:37:41.607 UTC: timer(0x62AD70B0) stops
Jun 10 22:37:41.607 UTC: timer(0x62AD7110) stops
Jun 10 22:37:41.607 UTC: timer(0x62AD70D0) stops
Jun 10 22:37:41.607 UTC: timer(0x62AD70F0) stops
Jun 10 22:37:41.607 UTC: timer(0x62AD7130) stops
Jun 10 22:37:41.607 UTC: timer(0x62AD72E0) stops
Jun 10 22:37:41.607 UTC: timer(0x62AD7000) stops
Jun 10 22:37:41.607 UTC: timer(0x62AD7020) stops
Jun 10 22:37:41.607 UTC: timer(0x62AD7368) stops
Jun 10 22:37:41.607 UTC: timer(0x62AD73A8) stops
Jun 10 22:37:41.607 UTC: timer(0x62AD6EB8) stops
Jun 10 22:37:41.607 UTC: timer(0x62AD7090) stops
Jun 10 22:37:41.607 UTC: timer(0x62AD70B0) stops
Jun 10 22:37:41.607 UTC: timer(0x62AD70D0) stops
Jun 10 22:37:41.607 UTC: timer(0x62AD70F0) stops
Jun 10 22:37:41.607 UTC: timer(0x62AD72E0) stops
Jun 10 22:37:41.607 UTC: timer(0x62AD7000) stops
Jun 10 22:37:41.607 UTC: timer(0x62AD7020) stops
Jun 10 22:37:41.607 UTC: timer(0x62AD7368) stops
Jun 10 22:37:41.607 UTC: timer(0x62AD73A8) stops
Jun 10 22:37:41.607 UTC: cc_api_call_disconnect_done(vdbPtr=0x0,
callID=0x3D, disp=0, tag=0x0)
Jun 10 22:37:41.607 UTC: cch323_call_generic_cleanup: freeing ccb
(0x62AD6B10)
Jun 10 22:37:41.607 UTC: sess_appl: ev(12=CC_EV_CALL_DISCONNECT_DONE),
cid(61), disp(0)
Jun 10 22:37:41.607 UTC:
cid(61)st(SSA_CS_DISCONNECTING)ev(SSA_EV_CALL_DISCONNECT_DONE)
oldst(SSA_CS_DISCONNECTING)cfid(-1)csize(0)in(1)fDest(1)
Jun 10 22:37:41.607 UTC: ssaDisconnectDone
Jun 10 22:37:43.095 UTC: ISDN Se1/1:15: TX -> RRp sapi=0 tei=0 nr=8
Jun 10 22:37:43.099 UTC: ISDN Se1/1:15: RX <- RRf sapi=0 tei=0 nr=13
Jun 10 22:37:43.295 UTC: ISDN Se1/1:15: RX <- RRp sapi=0 tei=0 nr=13
Jun 10 22:37:43.295 UTC: ISDN Se1/1:15: TX -> RRf sapi=0 tei=0 nr=8
It does not work.
Same for the other way around. When I dial in from the PSTN towards the
Cisco, the log says:
Jun 10 22:50:56.933 UTC: ISDN Se1/0:15: TX -> RRp sapi=0 tei=0 nr=59
Jun 10 22:50:56.937 UTC: ISDN Se1/0:15: RX <- RRf sapi=0 tei=0 nr=58
Jun 10 22:50:57.137 UTC: ISDN Se1/0:15: RX <- RRp sapi=0 tei=0 nr=58
Jun 10 22:50:57.137 UTC: ISDN Se1/0:15: TX -> RRf sapi=0 tei=0 nr=59
Jun 10 22:50:58.461 UTC: ISDN Se1/0:15: RX <- INFOc sapi=0 tei=0 ns=59
nr=58
i=0x0802002305A104039090A31803A1838F1E0282836C0B2183323633353130393438700AA1323034363835393235
Jun 10 22:50:58.465 UTC: SETUP pd = 8 callref = 0x0023
Jun 10 22:50:58.465 UTC: Sending Complete
Jun 10 22:50:58.465 UTC: Bearer Capability i = 0x9090A3
Jun 10 22:50:58.465 UTC: Channel ID i = 0xA1838F
Jun 10 22:50:58.465 UTC: Progress Ind i = 0x8283 - Origination
address is non-ISDN
Jun 10 22:50:58.465 UTC: Calling Party Number i = 0x21, 0x83,
'XXXXXXXXX', Plan:ISDN, Type:National
Jun 10 22:50:58.465 UTC: Called Party Number i = 0xA1,
'XXXXXXXXX', Plan:ISDN, Type:National
Jun 10 22:50:58.465 UTC: ISDN Se1/0:15: TX -> RRr sapi=0 tei=0 nr=60
Jun 10 22:50:58.465 UTC: ISDN Se1/0:15: Incoming call id = 0x000A, dsl 0
Jun 10 22:50:58.465 UTC: ISDN Se1/0:15: NegotiateBchan: bchan 15 intid 0
serv_st 0 chan_st 0 callid 0x0000 ev 0x90 n/w? 0
Jun 10 22:50:58.465 UTC: Negotiated int_id 0 bchan 0 cr=0x8023
callid=0x000A lo_chan 15 final int_id/bchan 0/15 cause 0x0
Jun 10 22:50:58.465 UTC: ISDN Se1/0:15: LIF_EVENT: ces/callid 1/0xA
CALL_INCOMING
Jun 10 22:50:58.465 UTC: ISDN Se1/0:15: CALL_INCOMING: call type is
VOICE ALAW, bchan = 14
Jun 10 22:50:58.465 UTC: ISDN Se1/0:15: call id 0xA call treated as DOV
Jun 10 22:50:58.465 UTC: ISDN Se1/0:15: Event: Received a DATA call
from XXXXXXXXX on B14 at 64 Kb/s
Jun 10 22:50:58.469 UTC: tsp_voice_call_check: called_number = XXXXXXXXX
Jun 10 22:50:58.469 UTC: tsp_voice_call_check: overlap = 0
Jun 10 22:50:58.469 UTC: tsp_voice_call_check: Matched inbound dial-peer
1 with port
Jun 10 22:50:58.469 UTC: tsp_voice_call_check: call is DID
Jun 10 22:50:58.469 UTC: tsp_voice_call_check: non-overlap call is DID
Jun 10 22:50:58.469 UTC: tsp_voice_call_check: Translate numbers prior
to outbound match
Jun 10 22:50:58.469 UTC: tsp_voice_call_check: Translated number
XXXXXXXXX ret 0
Jun 10 22:50:58.469 UTC: tsp_voice_call_check: DID + Matched outbound peer 2
Jun 10 22:50:58.469 UTC: CDAPI Se1/0:15: TX -> CDAPI_MSG_CONNECT_IND to
TSP CDAPI Application Voice call = 0xA
Jun 10 22:50:58.469 UTC: From Appl/Stack = ISDN
Jun 10 22:50:58.469 UTC: Call Type = DATA
Jun 10 22:50:58.469 UTC: B Channel = 14
Jun 10 22:50:58.469 UTC: Cause = 0
Jun 10 22:50:58.469 UTC: Calling Party Number = XXXXXXXXX
Jun 10 22:50:58.469 UTC: Called Party Number = XXXXXXXXX
Jun 10 22:50:58.469 UTC: CDAPI TSP RX ===> callId=(A ), MsgType=(1 )
Sub=(1 )cdapi_tsp_connect_ind
Jun 10 22:50:58.469 UTC: cdapi_tsp_connect_ind calling 0ct3 0x21,
called oct3 0xA1,
oct3a 0x83,mask 0x3F, callingIE 1
Jun 10 22:50:58.469 UTC: sub_calling oct3:len:data=0x0:0:,
Jun 10 22:50:58.469 UTC: sub_called oct3:len:data=0x0:0:
Jun 10 22:50:58.469 UTC: cdapi_tsp_connect_ind: is_overlap = 0
Jun 10 22:50:58.469 UTC: cdapi_tsp_connect_ind: info_complete = 0
Jun 10 22:50:58.469 UTC: Raw Message MaMa is TSP owner is TSP, length is
40, ptr is 626F0690, type is 0, protocol id is 1
Jun 10 22:50:58.469 UTC: Raw Message is : A1 04 03 90 90 A3 18 03 A1 83
8F 1E 02 82 83 6C 0B 21 83 32 36 33 35 31 30 39 34 38 70 0A A1 32 30 34
36 38 35 39 32 35
Jun 10 22:50:58.469 UTC: tsp_cdapi_msg_free returns 1
Jun 10 22:50:58.469 UTC: tsp_process_event: [1/0:15, S_TSP_INCALL,
E_TSP_RELEASE_REQ] tsp_cdapi_disconnect_req
Jun 10 22:50:58.469 UTC: tsp_cdapi_form_msg: type 8 tsp_cdb->prog_ind 0
Jun 10 22:50:58.469 UTC: CDAPI Se1/0:15: TX -> CDAPI_MSG_DISCONNECT_REQ
to ISDN call = 0xA
Jun 10 22:50:58.469 UTC: From Appl/Stack = TSP CDAPI Application
Voice
Jun 10 22:50:58.469 UTC: Call Type = DATA
Jun 10 22:50:58.469 UTC: B Channel = 14
Jun 10 22:50:58.469 UTC: Cause = 47
Jun 10 22:50:58.469 UTC: %SYS-2-LINKED: Bad enqueue of 622FC870 in queue
61BC8C98
-Process= "VTSP", ipl= 4, pid= 88
-Traceback= 60637538 60D82E40 60F1E478 60F1E9F0 60EE90EC 60F07B64
60F08394 60EF977C 60EF9B5C
Jun 10 22:50:58.473 UTC: CDAPI-ISDN Se1/0:15: RX <-
CDAPI_MSG_DISCONNECT_REQ from TSP CDAPI Application Voice call = 0xA
Jun 10 22:50:58.473 UTC: Call Type = DATA
Jun 10 22:50:58.473 UTC: B Channel = 14
Jun 10 22:50:58.473 UTC: Cause = 47
Jun 10 22:50:58.473 UTC: ISDN Se1/0:15: process_disconnect(): call id
0xA, call type is DATA, b_idb 0x625C0BDC, ces 1, cause Resource
unavailable, unspecified(0x2F)
Jun 10 22:50:58.473 UTC: ISDN Se1/0:15: CCPRI_ReleaseCall(): bchan 15,
call id 0xA, call type DATA
Jun 10 22:50:58.473 UTC: CCPRI_ReleaseChan released b_dsl 0 B_Chan 15
Jun 10 22:50:58.473 UTC: ISDN Se1/0:15: LIF_EVENT: ces/callid 1/0xA
CALL_CLEARED
Jun 10 22:50:58.473 UTC: ISDN Se1/0:15: received CALL_CLEARED call_id 0xA
Jun 10 22:50:58.473 UTC: no resend setup, no redial
Jun 10 22:50:58.473 UTC: CDAPI Se1/0:15: TX ->
CDAPI_MSG_SUBTYPE_REL_COMP_IND to TSP CDAPI Application Voice call = 0xA
Jun 10 22:50:58.473 UTC: From Appl/Stack = ISDN
Jun 10 22:50:58.473 UTC: Call Type = DATA
Jun 10 22:50:58.473 UTC: B Channel = 14
Jun 10 22:50:58.473 UTC: Cause = 0
Jun 10 22:50:58.473 UTC: CDAPI TSP RX ===> callId=(A ), MsgType=(9 )
Sub=(14)
Jun 10 22:50:58.473 UTC: tsp_cdapi_msg_free returns 1
Jun 10 22:50:58.473 UTC: ISDN Se1/0:15: TX -> INFOc sapi=0 tei=0 ns=58
nr=60 i=0x080280235A080280AF
Jun 10 22:50:58.473 UTC: RELEASE_COMP pd = 8 callref = 0x8023
Jun 10 22:50:58.473 UTC: Cause i = 0x80AF - Resource
unavailable, unspecified
Jun 10 22:50:58.481 UTC: ISDN Se1/0:15: RX <- RRr sapi=0 tei=0 nr=59
Jun 10 22:50:58.725 UTC: ISDN Se1/1:15: TX -> RRp sapi=0 tei=0 nr=8
Jun 10 22:50:58.729 UTC: ISDN Se1/1:15: RX <- RRf sapi=0 tei=0 nr=13
Jun 10 22:50:58.925 UTC: ISDN Se1/1:15: RX <- RRp sapi=0 tei=0 nr=13
Jun 10 22:50:58.925 UTC: ISDN Se1/1:15: TX -> RRf sapi=0 tei=0 nr=8
I hope someone with more experience can give me some pointers. I don't
know much about the PRI being used (it is a leftover in the company,
that I use in my VoIP-tests now). Are there any differences/flavours in
PRI's? This one is from KPN and it was used once for a dialin/dialup access.
Thanks for taking the time to browse through all the information in this
mail. Please do not hesitate to ask for further details!
Greetings,
--
Marco
More information about the cisco-voip
mailing list