E1 PRI generates errors with calls from GW

[alejandrortiz]

We are installing a voice gateway (ISR4351) with E1, and the device is comunicated with CUCM through SIP trunk. The calls from IPPhones are coming to the device, but when te call is transferred to E1 through dial-peers, the call is not working. These are te loggs:

GW_VOICE#
*Sep 20 21:37:20.327: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
INVITE sip:0782483501@172.20.4.15:5060 SIP/2.0
Via: SIP/2.0/TCP 192.168.60.117:5060;branch=z9hG4bKa41454c09aa4
From: "Tel_Pruebas" <sip:17111@192.168.60.117>;tag=46472~bdb7cf91-e321-412b-a18a-2c6e2fdb552d-48310392
To: <sip:0782483501@172.20.4.15>
Date: Fri, 20 Sep 2019 21:33:22 GMT
Call-ID: 43e90280-d85145a2-a337-753ca8c0@192.168.60.117
Supported: timer,resource-priority,replaces
Min-SE: 1800
User-Agent: Cisco-CUCM11.5
Allow: INVITE, OPTIONS, INFO, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY
CSeq: 101 INVITE
Expires: 180
Allow-Events: presence
Supported: X-cisco-srtp-fallback,X-cisco-original-called
Call-Info: <urn:x-cisco-remotecc:callinfo>;x-cisco-video-traffic-class=DESKTOP
Session-ID: 4d2e10d100105000a00000451d6e1493;remote=00000000000000000000000000000000
Cisco-Guid: 1139344000-0000065536-0000000208-1966909632
Session-Expires: 1800
P-Asserted-Identity: "Tel_Pruebas" <sip:17111@192.168.60.117>
Remote-Party-ID: "Tel_Pruebas" <sip:17111@192.168.60.117>;party=calling;screen=yes;privacy=off
Contact: <sip:17111@192.168.60.117:5060;transport=tcp>;+u.sip!devicename.ccm.cisco.com="SEP00451D6E1493"
Max-Forwards: 69
Content-Length: 0

*Sep 20 21:37:20.329: //-1/43E902800000/CCAPI/cc_api_display_ie_subfields:
cc_api_call_setup_ind_common:
cisco-username=17111
----- ccCallInfo IE subfields -----
cisco-ani=sip:17111@192.168.60.117
cisco-anitype=0
cisco-aniplan=0
cisco-anipi=0
cisco-anisi=1
dest=sip:0782483501@172.20.4.15:5060
cisco-desttype=0
cisco-destplan=0
cisco-rdie=FFFFFFFFFFFFFFFF
cisco-rdn=
cisco-rdntype=0
cisco-rdnplan=0
cisco-rdnpi=-1
cisco-rdnsi=-1
cisco-redirectreason=-1 fwd_final_type =0
final_redirectNumber =
hunt_group_timeout =0

*Sep 20 21:37:20.331: //-1/43E902800000/CCAPI/cc_api_call_setup_ind_common:
Interface=0x7F0F749EFEF8, Call Info(
Calling Number=sip:17111@192.168.60.117,(Calling Name=)(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed),
Called Number=sip:0782483501@172.20.4.15:5060(TON=Unknown, NPI=Unknown),
Calling Translated=FALSE, Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE,
Incoming Dial-peer=2, Progress Indication=NULL(0), Calling IE Present=TRUE,
Source Trkgrp Route Label=, Target Trkgrp Route Label=, CLID Transparent=FALSE), Call Id=78
*Sep 20 21:37:20.331: //-1/43E902800000/CCAPI/ccCheckClipClir:
In: Calling Number=sip:17111@192.168.60.117(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed)
*Sep 20 21:37:20.331: //-1/43E902800000/CCAPI/ccCheckClipClir:
Out: Calling Number=sip:17111@192.168.60.117(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed)
*Sep 20 21:37:20.331: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Sep 20 21:37:20.331: :cc_get_feature_vsa malloc success
*Sep 20 21:37:20.331: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Sep 20 21:37:20.331: cc_get_feature_vsa count is 1
*Sep 20 21:37:20.332: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Sep 20 21:37:20.332: :FEATURE_VSA attributes are: feature_name:0,feature_time:139704377383020,feature_id:9
*Sep 20 21:37:20.332: //78/43E902800000/CCAPI/cc_api_call_setup_ind_common:
Set Up Event Sent;
Call Info(Calling Number=(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed),
Called Number=(TON=Unknown, NPI=Unknown))
*Sep 20 21:37:20.332: //78/43E902800000/CCAPI/cc_process_call_setup_ind:
Event=0x7F0F75CBB340
*Sep 20 21:37:20.332: //-1/xxxxxxxxxxxx/CCAPI/cc_setupind_match_search:
Try with the demoted called number 0782483501
*Sep 20 21:37:20.333: //78/43E902800000/CCAPI/ccCallSetContext:
Context=0x7F0F7E6BEB68
*Sep 20 21:37:20.333: //78/43E902800000/CCAPI/cc_process_call_setup_ind:
>>>>CCAPI handed cid 78 with tag 2 to app "_ManagedAppProcess_Default"
*Sep 20 21:37:20.333: //78/43E902800000/CCAPI/ccCallProceeding:
Progress Indication=NULL(0)
*Sep 20 21:37:20.333: //-1/xxxxxxxxxxxx/CCAPI/ccGetMemPoolFromContainer:
mempool not found from usrContainer(7F0F7E836598)
*Sep 20 21:37:20.333: //-1/xxxxxxxxxxxx/CCAPI/ccCreateMemPoolInContainer:
Mempool(7F0F7E84EAD8) created in usrContainer(7F0F7E836598)
*Sep 20 21:37:20.334: //78/43E902800000/CCAPI/ccCallSetupRequest:
Destination=, Calling IE Present=TRUE, Mode=0,
Outgoing Dial-peer=11, Params=0x7F0F7E6C02E8, Progress Indication=NULL(0)
*Sep 20 21:37:20.334: //78/43E902800000/CCAPI/ccCheckClipClir:
In: Calling Number=sip:17111@192.168.60.117(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed)
*Sep 20 21:37:20.334: //78/43E902800000/CCAPI/ccCheckClipClir:
Out: Calling Number=sip:17111@192.168.60.117(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed)
*Sep 20 21:37:20.334: //78/43E902800000/CCAPI/ccCallSetupRequest:
Destination Pattern=07........$, Called Number=0782483501, Digit Strip=TRUE
*Sep 20 21:37:20.334: //78/43E902800000/CCAPI/ccCallSetupRequest:
Calling Number=sip:17111@192.168.60.117(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed),
Called Number=0782483501(TON=Unknown, NPI=Unknown),
Redirect Number=, Display Info=Tel_Pruebas
Account Number=17111, Final Destination Flag=TRUE,
Guid=43E90280-0001-0000-0000-00D0753CA8C0, Outgoing Dial-peer=11
*Sep 20 21:37:20.335: //78/43E902800000/CCAPI/cc_api_display_ie_subfields:
ccCallSetupRequest:
cisco-username=17111
----- ccCallInfo IE subfields -----
cisco-ani=sip:17111@192.168.60.117
cisco-anitype=0
cisco-aniplan=0
cisco-anipi=0
cisco-anisi=1
dest=0782483501
cisco-desttype=0
cisco-destplan=0
cisco-rdie=FFFFFFFFFFFFFFFF
cisco-rdn=
cisco-rdntype=0
cisco-rdnplan=0
cisco-rdnpi=-1
cisco-rdnsi=-1
cisco-redirectreason=-1 fwd_final_type =0
final_redirectNumber =
hunt_group_timeout =0

*Sep 20 21:37:20.336: //78/43E902800000/CCAPI/ccIFCallSetupRequestPrivate:
Interface=0x7F0F7DBD8E48, Interface Type=6, Destination=, Mode=0x0,
Call Params(Calling Number=sip:17111@192.168.60.117,(Calling Name=Tel_Pruebas)(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed),
Called Number=0782483501(TON=Unknown, NPI=Unknown), Calling Translated=FALSE,
Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE, Outgoing Dial-peer=11, Call Count On=FALSE,
Source Trkgrp Route Label=, Target Trkgrp Route Label=, tg_label_flag=0, Application Call Id=)
*Sep 20 21:37:20.336: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Sep 20 21:37:20.336: :cc_get_feature_vsa malloc success
*Sep 20 21:37:20.336: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Sep 20 21:37:20.336: cc_get_feature_vsa count is 2
*Sep 20 21:37:20.336: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Sep 20 21:37:20.336: :FEATURE_VSA attributes are: feature_name:0,feature_time:139704377383244,feature_id:10
*Sep 20 21:37:20.336: //79/43E902800000/CCAPI/ccIFCallSetupRequestPrivate:
SPI Call Setup Request Is Success; Interface Type=6, FlowMode=1
*Sep 20 21:37:20.336: //79/43E902800000/CCAPI/ccCallSetContext:
Context=0x7F0F7E6C0268
*Sep 20 21:37:20.337: //78/43E902800000/CCAPI/ccSaveDialpeerTag:
Outgoing Dial-peer=11
*Sep 20 21:37:20.338: //78/43E902800000/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 100 Trying
Via: SIP/2.0/TCP 192.168.60.117:5060;branch=z9hG4bKa41454c09aa4
From: "Tel_Pruebas" <sip:17111@192.168.60.117>;tag=46472~bdb7cf91-e321-412b-a18a-2c6e2fdb552d-48310392
To: <sip:0782483501@172.20.4.15>
Date: Fri, 20 Sep 2019 21:37:20 GMT
Call-ID: 43e90280-d85145a2-a337-753ca8c0@192.168.60.117
CSeq: 101 INVITE
Allow-Events: telephone-event
Server: Cisco-SIPGateway/IOS-16.9.3
Session-ID: 00000000000000000000000000000000;remote=4d2e10d100105000a00000451d6e1493
Content-Length: 0

*Sep 20 21:37:20.430: //79/43E902800000/CCAPI/cc_api_call_disconnected:
Cause Value=16, Interface=0x7F0F7DBD8E48, Call Id=79
*Sep 20 21:37:20.430: //79/43E902800000/CCAPI/cc_api_call_disconnected:
Call Entry(Responsed=TRUE, Cause Value=16, Retry Count=0)
*Sep 20 21:37:20.431: //78/43E902800000/CCAPI/ccCallReleaseResources:
release reserved xcoding resource.
*Sep 20 21:37:20.431: //79/43E902800000/CCAPI/ccCallSetAAA_Accounting:
Accounting=0, Call Id=79
*Sep 20 21:37:20.431: //79/43E902800000/CCAPI/ccCallDisconnect:
Cause Value=16, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=16)
*Sep 20 21:37:20.431: //79/43E902800000/CCAPI/ccCallDisconnect:
Cause Value=16, Call Entry(Responsed=TRUE, Cause Value=16)
*Sep 20 21:37:20.431: //79/43E902800000/CCAPI/cc_api_get_transfer_info:
Transfer Number=NULL
*Sep 20 21:37:20.432: //79/43E902800000/CCAPI/cc_api_call_disconnect_done:
Disposition=0, Interface=0x7F0F7DBD8E48, Tag=0x0, Call Id=79,
Call Entry(Disconnect Cause=16, Voice Class Cause Code=0, Retry Count=0)
*Sep 20 21:37:20.432: //79/43E902800000/CCAPI/cc_api_call_disconnect_done:
Call Disconnect Event Sent
*Sep 20 21:37:20.432: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*Sep 20 21:37:20.432: :cc_free_feature_vsa freeing 7F0F75C99940
*Sep 20 21:37:20.432: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*Sep 20 21:37:20.432: vsacount in free is 1
*Sep 20 21:37:20.432: //78/43E902800000/CCAPI/ccCallDisconnect:
Cause Value=16, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=0)
*Sep 20 21:37:20.433: //78/43E902800000/CCAPI/ccCallDisconnect:
Cause Value=16, Call Entry(Responsed=TRUE, Cause Value=16)
*Sep 20 21:37:20.433: //-1/xxxxxxxxxxxx/CCAPI/ccMemPoolTDFreeHelper:
data = 7F0F7E8372D8
*Sep 20 21:37:20.433: ccMemPoolTDFreeHelper:mem_mgr_mempool_free: mem_refcnt(7F0F7E84EAD8)=0 - mempool cleanup
*Sep 20 21:37:20.434: //78/43E902800000/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 500 Internal Server Error
Via: SIP/2.0/TCP 192.168.60.117:5060;branch=z9hG4bKa41454c09aa4
From: "Tel_Pruebas" <sip:17111@192.168.60.117>;tag=46472~bdb7cf91-e321-412b-a18a-2c6e2fdb552d-48310392
To: <sip:0782483501@172.20.4.15>;tag=7550E-1032
Date: Fri, 20 Sep 2019 21:37:20 GMT
Call-ID: 43e90280-d85145a2-a337-753ca8c0@192.168.60.117
CSeq: 101 INVITE
Allow-Events: telephone-event
Server: Cisco-SIPGateway/IOS-16.9.3
Reason: Q.850;cause=16
Session-ID: 4d2e10d100105000a00000451d6e1493;remote=ac4e008c936e5c5eafc778d5fea2a7c4
Content-Length: 0

*Sep 20 21:37:20.438: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
ACK sip:0782483501@172.20.4.15:5060 SIP/2.0
Via: SIP/2.0/TCP 192.168.60.117:5060;branch=z9hG4bKa41454c09aa4
From: "Tel_Pruebas" <sip:17111@192.168.60.117>;tag=46472~bdb7cf91-e321-412b-a18a-2c6e2fdb552d-48310392
To: <sip:0782483501@172.20.4.15>;tag=7550E-1032
Date: Fri, 20 Sep 2019 21:33:22 GMT
Call-ID: 43e90280-d85145a2-a337-753ca8c0@192.168.60.117
User-Agent: Cisco-CUCM11.5
Max-Forwards: 70
CSeq: 101 ACK
Allow-Events: presence
Content-Length: 0

*Sep 20 21:37:20.439: //78/43E902800000/CCAPI/cc_api_call_disconnect_done:
Disposition=0, Interface=0x7F0F749EFEF8, Tag=0x0, Call Id=78,
Call Entry(Disconnect Cause=16, Voice Class Cause Code=0, Retry Count=0)
*Sep 20 21:37:20.439: //78/43E902800000/CCAPI/cc_api_call_disconnect_done:
Call Disconnect Event Sent
*Sep 20 21:37:20.439: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*Sep 20 21:37:20.439: :cc_free_feature_vsa freeing 7F0F75C99860
*Sep 20 21:37:20.439: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*Sep 20 21:37:20.439: vsacount in free is 0
*Sep 20 21:37:20.439: //78/43E902800000/SIP/Call/sipSPICallInfo:
The Call Setup Information is:
Call Control Block (CCB) : 0x0x7F0F7BEB8520
State of The Call : STATE_DEAD
TCP Sockets Used : YES
Calling Number : 17111
Called Number : 0782483501
Source IP Address (Sig ): 172.20.4.15
Destn SIP Req Addr:Port : 192.168.60.117:5060
Destn SIP Resp Addr:Port : 192.168.60.117:58077
Destination Name : 192.168.60.117

GW_VOICE_PCC#
GW_VOICE_PCC#
GW_VOICE_PCC#
*Sep 20 21:37:20.439: //78/43E902800000/SIP/Call/sipSPIMediaCallInfo:
Number of Media Streams: 1
Media Stream : 1
Negotiated Codec : No Codec
Negotiated Codec Bytes : 0
Nego. Codec payload : 255 (tx), 255 (rx)
Negotiated Dtmf-relay : 0
Dtmf-relay Payload : 0 (tx), 0 (rx)
Source IP Address (Media): 172.20.4.15
Source IP Port (Media): 8008
Destn IP Address (Media): -
Destn IP Port (Media): 0
Orig Destn IP Address:Port (Media): [ - ]:0

*Sep 20 21:37:20.439: //78/43E902800000/SIP/Call/sipSPICallInfo:
Disconnect Cause (CC) : 16
Disconnect Cause (SIP) : 500

GW_VOICE#
*Sep 20 22:04:07.974: ISDN Se0/1/0:15 Q921: User TX -> INFO sapi=0 tei=0, ns=96 nr=87
*Sep 20 22:04:07.987: ISDN Se0/1/0:15 Q921: User RX <- RR sapi=0 tei=0 nr=97
*Sep 20 22:04:08.007: ISDN Se0/1/0:15 Q921: User RX <- INFO sapi=0 tei=0, ns=87 nr=97
*Sep 20 22:04:08.007: ISDN Se0/1/0:15 Q921: User TX -> RR sapi=0 tei=0 nr=88
*Sep 20 22:04:08.007: ISDN Se0/1/0:15 **ERROR**: Ux_BadMsg: Invalid Message for call state 1, call id 0x8012, call ref 0x91, event 0xD
*Sep 20 22:04:08.008: ISDN Se0/1/0:15 Q921: User TX -> INFO sapi=0 tei=0, ns=97 nr=88
*Sep 20 22:04:08.020: ISDN Se0/1/0:15 Q921: User RX <- RR sapi=0 tei=0 nr=98
*Sep 20 22:04:08.327: ISDN Se0/1/0:15 Q921: User RX <- INFO sapi=0 tei=0, ns=88 nr=98
*Sep 20 22:04:08.327: ISDN Se0/1/0:15 Q921: User TX -> RR sapi=0 tei=0 nr=89
*Sep 20 22:04:08.327: ISDN Se0/1/0:15 Q921: User TX -> INFO sapi=0 tei=0, ns=98 nr=89
*Sep 20 22:04:08.339: ISDN Se0/1/0:15 Q921: User RX <- RR sapi=0 tei=0 nr=99
*Sep 20 22:04:08.420: ISDN Se0/1/0:15 Q921: User RX <- INFO sapi=0 tei=0, ns=89 nr=99
*Sep 20 22:04:08.420: ISDN Se0/1/0:15 Q921: User TX -> RR sapi=0 tei=0 nr=90
*Sep 20 22:04:08.420: ISDN Se0/1/0:15 Q921: User TX -> INFO sapi=0 tei=0, ns=99 nr=90
*Sep 20 22:04:08.431: ISDN Se0/1/0:15 Q921: User RX <- RR sapi=0 tei=0 nr=100
*Sep 20 22:04:08.440: ISDN Se0/1/0:15 Q921: User RX <- INFO sapi=0 tei=0, ns=90 nr=100
*Sep 20 22:04:08.440: ISDN Se0/1/0:15 Q921: User TX -> RR sapi=0 tei=0 nr=91

I would appreciate if someone can help me. Thanks.

[Vaijanath Sonvane]

Hi,

Can you post full configuration of your router? Also, you are sending 5 digit extension as your calling number to the service provider. Does your service provider accept internal extensions?

[Mohammed al Baqari]

Hi,

You are matching dialpeer 11 to send the calls to pstn. Are you having
correct voice translation on the dialpeer to pass the digits to telco? The
cause code is 16 which is normal call clearing and I suspect the passed
numbers are wrong.

Are you using r2 e1 or e1 pri.? If e1 pri you can get isdn q931 as well to
see what is happening on isdn side

Remember to rate useful posts