Outbound Ringback Issues

Having a weird issue with outbound ringback on the calling phone. Ring back works fine on imcoming PSTN calls and on-net calls, but when calling OUT to the PSTN (via sip trunk on voip.ms) i get no ringback, its just dead silence. The call does work, the phone rings on the other end and you can pickup and the call completes OK, theres just no ringback on the calling phone going out.

Heres output from debug ccsip calls and debug voip ccapi inout

Thoughts?

Jun 11 03:38:38.947: //-1/805B96CD0300/CCAPI/cc_api_display_ie_subfields:
   cc_api_call_setup_ind_common:
   cisco-username=7001
   ----- ccCallInfo IE subfields -----
   cisco-ani=7001
   cisco-anitype=0
   cisco-aniplan=0
   cisco-anipi=0
   cisco-anisi=1
   dest=4023622211
   cisco-desttype=0
   cisco-destplan=0
   cisco-rdie=FFFFFFFF
   cisco-rdn=
   cisco-rdntype=-1
   cisco-rdnplan=-1
   cisco-rdnpi=-1
   cisco-rdnsi=-1
   cisco-redirectreason=-1   fwd_final_type =0
   final_redirectNumber =
   hunt_group_timeout =0
Jun 11 03:38:38.947: //-1/805B96CD0300/CCAPI/cc_api_call_setup_ind_common:
   Interface=0x6793663C, Call Info(
   Calling Number=7001,(Calling Name=)(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed),
   Called Number=4023622211(TON=Unknown, NPI=Unknown),
   Calling Translated=FALSE, Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE,
   Incoming Dial-peer=1, Progress Indication=NULL(0), Calling IE Present=TRUE,
   Source Trkgrp Route Label=, Target Trkgrp Route Label=, CLID Transparent=FALSE), Call Id=3580
Jun 11 03:38:38.947: //-1/805B96CD0300/CCAPI/ccCheckClipClir:
   In: Calling Number=7001(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed)
Jun 11 03:38:38.951: //-1/805B96CD0300/CCAPI/ccCheckClipClir:
   Out: Calling Number=7001(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed)
Jun 11 03:38:38.951: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
   
Jun 11 03:38:38.951: :cc_get_feature_vsa malloc success
Jun 11 03:38:38.951: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
   
Jun 11 03:38:38.951:  cc_get_feature_vsa count is 52
Jun 11 03:38:38.951: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
   
Jun 11 03:38:38.951: :FEATURE_VSA attributes are: feature_name:0,feature_time:1717184384,feature_id:326
Jun 11 03:38:38.951: //3580/805B96CD0300/CCAPI/cc_api_call_setup_ind_common:
   Set Up Event Sent;
   Call Info(Calling Number=7001(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed),
   Called Number=4023622211(TON=Unknown, NPI=Unknown))
Jun 11 03:38:38.951: //3580/805B96CD0300/CCAPI/cc_process_call_setup_ind:
   Event=0x67BFD448
Jun 11 03:38:38.951: //-1/xxxxxxxxxxxx/CCAPI/cc_setupind_match_search:
   Try with the demoted called number 4023622211
Jun 11 03:38:38.951: //3580/805B96CD0300/CCAPI/ccCallSetContext:
   Context=0x66694494
Jun 11 03:38:38.955: //3580/805B96CD0300/CCAPI/cc_process_call_setup_ind:
   >>>>CCAPI handed cid 3580 with tag 1 to app "_ManagedAppProcess_Default"
Jun 11 03:38:38.955: //3580/805B96CD0300/CCAPI/ccCallProceeding:
   Progress Indication=NULL(0)
Jun 11 03:38:38.959: //3580/805B96CD0300/CCAPI/ccCallSetupRequest:
   Destination=, Calling IE Present=TRUE, Mode=0,
   Outgoing Dial-peer=2, Params=0x6669A90C, Progress Indication=NULL(0)
Jun 11 03:38:38.959: //3580/805B96CD0300/CCAPI/ccCheckClipClir:
   In: Calling Number=7001(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed)
Jun 11 03:38:38.959: //3580/805B96CD0300/CCAPI/ccCheckClipClir:
   Out: Calling Number=7001(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed)
Jun 11 03:38:38.959: //3580/805B96CD0300/CCAPI/ccCallSetupRequest:
   Destination Pattern=., Called Number=4023622211, Digit Strip=FALSE
Jun 11 03:38:38.959: //3580/805B96CD0300/CCAPI/ccCallSetupRequest:
   Calling Number=7001(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed),
   Called Number=4023622211(TON=Unknown, NPI=Unknown),
   Redirect Number=, Display Info=
   Account Number=7001, Final Destination Flag=TRUE,
   Guid=805B96CD-5C66-51FD-0300-2801AC100115, Outgoing Dial-peer=2
Jun 11 03:38:38.959: //3580/805B96CD0300/CCAPI/cc_api_display_ie_subfields:
   ccCallSetupRequest:
   cisco-username=7001
   ----- ccCallInfo IE subfields -----
   cisco-ani=7001
   cisco-anitype=0
   cisco-aniplan=0
   cisco-anipi=0
   cisco-anisi=1
   dest=4023622211
   cisco-desttype=0
   cisco-destplan=0
   cisco-rdie=FFFFFFFF
   cisco-rdn=
   cisco-rdntype=-1
   cisco-rdnplan=-1
   cisco-rdnpi=-1
   cisco-rdnsi=-1
   cisco-redirectreason=-1   fwd_final_type =0
   final_redirectNumber =
   hunt_group_timeout =0
Jun 11 03:38:38.959: //3580/805B96CD0300/CCAPI/ccIFCallSetupRequestPrivate:
   Interface=0x6725DFF4, Interface Type=3, Destination=, Mode=0x0,
   Call Params(Calling Number=7001,(Calling Name=)(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed),
   Called Number=4023622211(TON=Unknown, NPI=Unknown), Calling Translated=FALSE,
   Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE, Outgoing Dial-peer=2, Call Count On=FALSE,
   Source Trkgrp Route Label=, Target Trkgrp Route Label=, tg_label_flag=0, Application Call Id=)
Jun 11 03:38:38.959: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
   
Jun 11 03:38:38.959: :cc_get_feature_vsa malloc success
Jun 11 03:38:38.959: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
   
Jun 11 03:38:38.959:  cc_get_feature_vsa count is 53
Jun 11 03:38:38.959: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
   
Jun 11 03:38:38.959: :FEATURE_VSA attributes are: feature_name:0,feature_time:1717184160,feature_id:327
Jun 11 03:38:38.963: //3581/805B96CD0300/CCAPI/ccIFCallSetupRequestPrivate:
   SPI Call Setup Request Is Success; Interface Type=3, FlowMode=1
Jun 11 03:38:38.963: //3581/805B96CD0300/CCAPI/ccCallSetContext:
   Context=0x6669A8BC
Jun 11 03:38:38.963: //3580/805B96CD0300/CCAPI/ccSaveDialpeerTag:
   Outgoing Dial-peer=2
Jun 11 03:38:38.963: //3581/805B96CD0300/CCAPI/cc_api_call_proceeding:
   Interface=0x6725DFF4, Progress Indication=NULL(0)
Jun 11 03:38:43.239: //3581/805B96CD0300/CCAPI/cc_api_caps_ind:
   Destination Interface=0x0, Destination Call Id=-1, Source Call Id=3581,
   Caps(Codec=0x4, Fax Rate=0x2, Vad=0x2,
   Modem=0x0, Codec Bytes=20, Signal Type=2)
Jun 11 03:38:43.239: //3581/805B96CD0300/CCAPI/cc_api_caps_ind:
   Caps(Playout Mode=1, Playout Initial=60(ms), Playout Min=40(ms),
   Playout Max=1000(ms), Fax Nom=300(ms))
Jun 11 03:38:43.239: //3581/805B96CD0300/CCAPI/cc_api_event_indication:
   Event=91, Call Id=3581
Jun 11 03:38:43.239: //3581/805B96CD0300/CCAPI/cc_api_event_indication:
   Event Is Sent To Conferenced SPI(s) Directly
Jun 11 03:38:43.239: //3581/805B96CD0300/CCAPI/cc_api_call_cut_progress:
   Interface=0x6725DFF4, Progress Indication=INBAND([IMG]https://us.v-cdn.net/6030959/uploads/images/smilies/icon_cool.gif[/IMG], Signal Indication=SIGNAL RINGBACK(1),
   Cause Value=0
Jun 11 03:38:43.243: //3581/805B96CD0300/CCAPI/cc_api_call_cut_progress:
   Call Entry(Responsed=TRUE)
Jun 11 03:38:43.243: //3580/805B96CD0300/CCAPI/ccCallCutProgress:
   Progress Indication=INBAND([IMG]https://us.v-cdn.net/6030959/uploads/images/smilies/icon_cool.gif[/IMG], Signal Indication=SIGNAL RINGBACK(1), Cause Value=0
   Voice Call Send Alert=FALSE, Call Entry(Alert Sent=FALSE)
Jun 11 03:38:43.243: //3580/805B96CD0300/CCAPI/ccCallCutProgress:
   Call Entry(Responsed=TRUE)
Jun 11 03:38:43.243: //3581/805B96CD0300/CCAPI/cc_api_get_called_ccm_detected:
   CallInfo(ccm detected=0)
Jun 11 03:38:43.243: //3580/805B96CD0300/CCAPI/ccConferenceCreate:
   (confID=0x66620A98, callID1=0xDFC, gcid=0-0-0-0, tag=0x0)
Jun 11 03:38:43.247: //3581/805B96CD0300/CCAPI/ccConferenceCreate:
   (confID=0x66620A98, callID2=0xDFD, gcid=0-0-0-0, tag=0x0)
Jun 11 03:38:43.247: //3580/805B96CD0300/CCAPI/ccConferenceCreate:
   Conference Id=0x66620A98, Call Id1=3580, Call Id2=3581, Tag=0x0
Jun 11 03:38:43.247: //3580/xxxxxxxxxxxx/CCAPI/cc_api_get_xcode_stream:
   
Jun 11 03:38:43.247: cc_api_get_xcode_stream : 4683
Jun 11 03:38:43.247: //3580/805B96CD0300/CCAPI/cc_api_bridge_done:
   Conference Id=0x2F, Source Interface=0x6793663C, Source Call Id=3580,
   Destination Call Id=3581, Disposition=0x0, Tag=0x0
Jun 11 03:38:43.247: //3581/xxxxxxxxxxxx/CCAPI/cc_api_get_xcode_stream:
   
Jun 11 03:38:43.247: cc_api_get_xcode_stream : 4683
Jun 11 03:38:43.247: //3581/805B96CD0300/CCAPI/cc_api_bridge_done:
   Conference Id=0x2F, Source Interface=0x6725DFF4, Source Call Id=3581,
   Destination Call Id=3580, Disposition=0x0, Tag=0x0
Jun 11 03:38:43.247: //3580/805B96CD0300/CCAPI/cc_generic_bridge_done:
   Conference Id=0x2F, Source Interface=0x6725DFF4, Source Call Id=3581,
   Destination Call Id=3580, Disposition=0x0, Tag=0x0
Jun 11 03:38:43.247: //3580/805B96CD0300/CCAPI/ccConferenceCreate:
   Call Entry(Conference Id=0x2F, Destination Call Id=3581)
Jun 11 03:38:43.247: //3581/805B96CD0300/CCAPI/ccConferenceCreate:
   Call Entry(Conference Id=0x2F, Destination Call Id=3580)
Jun 11 03:38:43.251: //3580/805B96CD0300/CCAPI/cc_process_notify_bridge_done:
   Conference Id=0x2F, Call Id1=3580, Call Id2=3581
Jun 11 03:38:43.251: //3580/805B96CD0300/CCAPI/ccCallNotify:
   Data Bitmask=0x7, Call Id=3580
Jun 11 03:38:43.251: //3581/805B96CD0300/CCAPI/cc_api_get_called_ccm_detected:
   CallInfo(ccm detected=0)
Jun 11 03:38:43.271: //3580/805B96CD0300/CCAPI/cc_api_caps_ind:
   Destination Interface=0x6725DFF4, Destination Call Id=3581, Source Call Id=3580,
   Caps(Codec=0x4, Fax Rate=0x2, Vad=0x2,
   Modem=0x0, Codec Bytes=20, Signal Type=2)
Jun 11 03:38:43.271: //3580/805B96CD0300/CCAPI/cc_api_caps_ind:
   Caps(Playout Mode=1, Playout Initial=60(ms), Playout Min=40(ms),
   Playout Max=1000(ms), Fax Nom=300(ms))
Jun 11 03:38:43.271: //3581/805B96CD0300/CCAPI/cc_api_caps_ack:
   Destination Interface=0x6793663C, Destination Call Id=3580, Source Call Id=3581,
   Caps(Codec=g729r8(0x4), Fax Rate=FAX_RATE_VOICE(0x2), Vad=ON(0x2),
   Modem=OFF(0x0), Codec Bytes=20, Signal Type=2, Seq Num Start=1)
Jun 11 03:38:43.271: //3580/805B96CD0300/CCAPI/cc_api_caps_ack:
   Destination Interface=0x6725DFF4, Destination Call Id=3581, Source Call Id=3580,
   Caps(Codec=gsmefr(0x0), Fax Rate=Invalid(0x0), Vad=Invalid(0x0),
   Modem=OFF(0x0), Codec Bytes=0, Signal Type=0, Seq Num Start=0)
Jun 11 03:38:43.295: //3580/805B96CD0300/CCAPI/cc_api_event_indication:
   Event=165, Call Id=3580
Jun 11 03:38:43.295: //3580/805B96CD0300/CCAPI/cc_api_event_indication:
   Event Is Sent To Conferenced SPI(s) Directly
Jun 11 03:38:43.295: //3581/805B96CD0300/CCAPI/cc_api_event_indication:
   Event=166, Call Id=3581
Jun 11 03:38:43.295: //3581/805B96CD0300/CCAPI/cc_api_event_indication:
   Event Is Sent To Conferenced SPI(s) Directly
Jun 11 03:38:43.347: //3580/805B96CD0300/CCAPI/cc_api_event_indication:
   Event=166, Call Id=3580
Jun 11 03:38:43.347: //3580/805B96CD0300/CCAPI/cc_api_event_indication:
   Event Is Sent To Conferenced SPI(s) Directly
Jun 11 03:38:53.037: //3581/805B96CD0300/CCAPI/cc_api_event_indication:
   Event=91, Call Id=3581
Jun 11 03:38:53.041: //3581/805B96CD0300/CCAPI/cc_api_event_indication:
   Event Is Sent To Conferenced SPI(s) Directly
Jun 11 03:38:53.041: //3581/805B96CD0300/CCAPI/cc_api_call_connected:
   Interface=0x6725DFF4, Data Bitmask=0x1, Progress Indication=NULL(0),
   Connection Handle=0
Jun 11 03:38:53.041: //3581/805B96CD0300/CCAPI/cc_api_call_connected:
   Call Entry(Connected=TRUE, Responsed=TRUE, Retry Count=0)
Jun 11 03:38:53.045: //3581/805B96CD0300/SIP/Call/sipSPICallInfo: 
The Call Setup Information is:
Call Control Block (CCB) : 0x68348F30
State of The Call        : STATE_ACTIVE
TCP Sockets Used         : NO
Calling Number           : 7001
Called Number            : 4023622211
Source IP Address (Sig  ): xx
Destn SIP Req Addr:Port  : 64.120.22.242:5060
Destn SIP Resp Addr:Port : 64.120.22.242:5060
Destination Name         : chicago.voip.ms
Jun 11 03:38:53.045: //3581/805B96CD0300/SIP/Call/sipSPIMediaCallInfo: 
Number of Media Streams: 1
Media Stream             : 1
Negotiated Codec         : g729r8
Negotiated Codec Bytes   : 20
Nego. Codec payload      : 18 (tx), 18 (rx)
Negotiated Dtmf-relay    : 6
Dtmf-relay Payload       : 101 (tx), 101 (rx)
Source IP Address (Media): xx
Source IP Port    (Media): 17196
Destn  IP Address (Media): 64.120.22.242
Destn  IP Port    (Media): 13520
Orig Destn IP Address:Port (Media): [ - ]:0
Jun 11 03:38:53.045: //3580/805B96CD0300/CCAPI/ccCallConnect:
   Progress Indication=NULL(0), Data Bitmask=0x1
Jun 11 03:38:53.049: //3581/805B96CD0300/CCAPI/cc_api_get_called_ccm_detected:
   CallInfo(ccm detected=0)
Jun 11 03:38:53.049: //3580/805B96CD0300/CCAPI/ccCallConnect:
   Call Entry(Connected=TRUE, Responsed=TRUE)
Jun 11 03:38:53.049: //3580/805B96CD0300/CCAPI/ccCallNotify:
   Data Bitmask=0x7, Call Id=3580
Jun 11 03:38:53.049: //3581/805B96CD0300/CCAPI/cc_api_get_called_ccm_detected:
   CallInfo(ccm detected=0)
Jun 11 03:38:56.705: //3580/805B96CD0300/CCAPI/cc_api_call_disconnected:
   Cause Value=16, Interface=0x6793663C, Call Id=3580
Jun 11 03:38:56.705: //3580/805B96CD0300/CCAPI/cc_api_call_disconnected:
   Call Entry(Responsed=TRUE, Cause Value=16, Retry Count=0)
Jun 11 03:38:56.709: //3580/805B96CD0300/CCAPI/ccConferenceDestroy:
   Conference Id=0x2F, Tag=0x0
Jun 11 03:38:56.709: //3580/805B96CD0300/CCAPI/cc_api_bridge_drop_done:
   Conference Id=0x2F, Source Interface=0x6793663C, Source Call Id=3580,
   Destination Call Id=3581, Disposition=0x0, Tag=0x0
Jun 11 03:38:56.709: //3581/805B96CD0300/CCAPI/cc_api_bridge_drop_done:
   Conference Id=0x2F, Source Interface=0x6725DFF4, Source Call Id=3581,
   Destination Call Id=3580, Disposition=0x0, Tag=0x0
Jun 11 03:38:56.709: //3580/805B96CD0300/CCAPI/cc_generic_bridge_done:
   Conference Id=0x2F, Source Interface=0x6725DFF4, Source Call Id=3581,
   Destination Call Id=3580, Disposition=0x0, Tag=0x0
Jun 11 03:38:56.713: //3580/805B96CD0300/CCAPI/ccCallDisconnect:
   Cause Value=16, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=16)
Jun 11 03:38:56.713: //3580/805B96CD0300/CCAPI/ccCallDisconnect:
   Cause Value=16, Call Entry(Responsed=TRUE, Cause Value=16)
Jun 11 03:38:56.713: //3580/805B96CD0300/CCAPI/cc_api_get_transfer_info:
   Transfer Number Is Null
Jun 11 03:38:56.713: //3581/805B96CD0300/CCAPI/ccCallDisconnect:
   Cause Value=16, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=0)
Jun 11 03:38:56.713: //3581/805B96CD0300/CCAPI/ccCallDisconnect:
   Cause Value=16, Call Entry(Responsed=TRUE, Cause Value=16)
Jun 11 03:38:56.717: //3580/805B96CD0300/CCAPI/cc_api_call_disconnect_done:
   Disposition=0, Interface=0x6793663C, Tag=0x0, Call Id=3580,
   Call Entry(Disconnect Cause=16, Voice Class Cause Code=0, Retry Count=0)
Jun 11 03:38:56.717: //3580/805B96CD0300/CCAPI/cc_api_call_disconnect_done:
   Call Disconnect Event Sent
Jun 11 03:38:56.717: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
   
Jun 11 03:38:56.717: :cc_free_feature_vsa freeing 665A2778
Jun 11 03:38:56.717: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
   
Jun 11 03:38:56.717:  vsacount in free is 52
Jun 11 03:38:56.741: //3581/805B96CD0300/CCAPI/cc_api_call_disconnect_done:
   Disposition=0, Interface=0x6725DFF4, Tag=0x0, Call Id=3581,
   Call Entry(Disconnect Cause=16, Voice Class Cause Code=0, Retry Count=0)
Jun 11 03:38:56.741: //3581/805B96CD0300/CCAPI/cc_api_call_disconnect_done:
   Call Disconnect Event Sent
Jun 11 03:38:56.741: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
   
Jun 11 03:38:56.741: :cc_free_feature_vsa freeing 665A2698
Jun 11 03:38:56.741: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
   
Jun 11 03:38:56.741:  vsacount in free is 51
Jun 11 03:38:56.741: //3581/805B96CD0300/SIP/Call/sipSPICallInfo: 
The Call Setup Information is:
Call Control Block (CCB) : 0x68348F30
State of The Call        : STATE_DEAD
TCP Sockets Used         : NO
Calling Number           : 7001
Called Number            : 4023622211
Source IP Address (Sig  ): xx
Destn SIP Req Addr:Port  : 64.120.22.242:5060
Destn SIP Resp Addr:Port : 64.120.22.242:5060
Destination Name         : chicago.voip.ms
Jun 11 03:38:56.741: //3581/805B96CD0300/SIP/Call/sipSPIMediaCallInfo: 
Number of Media Streams: 1
Media Stream             : 1
Negotiated Codec         : g729r8
Negotiated Codec Bytes   : 20
Nego. Codec payload      : 18 (tx), 18 (rx)
Negotiated Dtmf-relay    : 6
Dtmf-relay Payload       : 101 (tx), 101 (rx)
Source IP Address (Media): XX
Source IP Port    (Media): 17196
Destn  IP Address (Media): 64.120.22.242
Destn  IP Port    (Media): 13520
Orig Destn IP Address:Port (Media): [ - ]:0
Jun 11 03:38:56.741: //3581/805B96CD0300/SIP/Call/sipSPICallInfo: 
Disconnect Cause (CC)    : 16
Disconnect Cause (SIP)   : 200

Find more posts tagged with

Comments

pitviper

Try the following under sip-ua: "disable-early-media 180"

Also, please post the output of "debug ccsip message".

JZegers

added the command with no dice, heres output of debug ccsip messages on an outbound call. call connects OK, just no ringing on phone placing the call.

Jun 11 23:08:39.206: //4032/80470C400700/SIP/Msg/ccsipDisplayMsg:
Sent: 
INVITE sip:4023622211@chicago.voip.ms:5060 SIP/2.0

Via: SIP/2.0/UDP PUBLIC_IP:5060;branch=z9hG4bK1CC26D6

From: "7001" <sip:7001@PUBLIC_IP>;tag=42E873C4-1FF0

To: <sip:4023622211@chicago.voip.ms>

Date: Mon, 11 Jun 2012 23:08:39 GMT

Call-ID: 36D5630F-B35111E1-858D874F-1E64976B@dns.name.of.your.device

Supported: 100rel,timer,resource-priority,replaces,sdp-anat

Min-SE:  1800

Cisco-Guid: 2152139840-2490917373-0117451777-2886730005

User-Agent: Cisco-SIPGateway/IOS-12.x

Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER

CSeq: 101 INVITE

Max-Forwards: 70

Timestamp: 1339456119

Contact: <sip:7001@PUBLIC_IP:5060>

Expires: 180

Allow-Events: telephone-event

P-Preferred-Identity: "7001" <sip:7001@dns.name.of.your.device>

Content-Length: 0

 
 
 
Jun 11 23:08:39.226: //4032/80470C400700/SIP/Msg/ccsipDisplayMsg:
Received: 
SIP/2.0 407 Proxy Authentication Required

Via: SIP/2.0/UDP PUBLIC_IP:5060;branch=z9hG4bK1CC26D6;received=PUBLIC_IP

From: "7001" <sip:7001@PUBLIC_IP>;tag=42E873C4-1FF0

To: <sip:4023622211@chicago.voip.ms>;tag=as149b668f

Call-ID: 36D5630F-B35111E1-858D874F-1E64976B@dns.name.of.your.device

CSeq: 101 INVITE

User-Agent: VoIPMS/SERAST

Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO

Supported: replaces

Proxy-Authenticate: Digest algorithm=MD5, realm="chicago.voip.ms", nonce="4778b4e0"

Content-Length: 0

 
 
 
Jun 11 23:08:39.230: //4032/80470C400700/SIP/Msg/ccsipDisplayMsg:
Sent: 
ACK sip:4023622211@chicago.voip.ms:5060 SIP/2.0

Via: SIP/2.0/UDP PUBLIC_IP:5060;branch=z9hG4bK1CC26D6

From: "7001" <sip:7001@PUBLIC_IP>;tag=42E873C4-1FF0

To: <sip:4023622211@chicago.voip.ms>;tag=as149b668f

Date: Mon, 11 Jun 2012 23:08:39 GMT

Call-ID: 36D5630F-B35111E1-858D874F-1E64976B@dns.name.of.your.device

Max-Forwards: 70

CSeq: 101 ACK

Allow-Events: telephone-event

Content-Length: 0

 
 
 
Jun 11 23:08:39.234: //4032/80470C400700/SIP/Msg/ccsipDisplayMsg:
Sent: 
INVITE sip:4023622211@chicago.voip.ms:5060 SIP/2.0

Via: SIP/2.0/UDP PUBLIC_IP:5060;branch=z9hG4bK1CC3F08

From: "7001" <sip:7001@PUBLIC_IP>;tag=42E873C4-1FF0

To: <sip:4023622211@chicago.voip.ms>

Date: Mon, 11 Jun 2012 23:08:39 GMT

Call-ID: 36D5630F-B35111E1-858D874F-1E64976B@dns.name.of.your.device

Supported: 100rel,timer,resource-priority,replaces,sdp-anat

Min-SE:  1800

Cisco-Guid: 2152139840-2490917373-0117451777-2886730005

User-Agent: Cisco-SIPGateway/IOS-12.x

Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER

CSeq: 102 INVITE

Max-Forwards: 70

Timestamp: 1339456119

Contact: <sip:7001@PUBLIC_IP:5060>

Expires: 180

Allow-Events: telephone-event

Proxy-Authorization: Digest username="141513",realm="chicago.voip.ms",uri="sip:4023622211@chicago.voip.ms:5060",response="48d595b26162c614cd77f2b1c3c2f4a0",nonce="4778b4e0",algorithm=MD5

P-Preferred-Identity: "7001" <sip:7001@dns.name.of.your.device>

Content-Length: 0

 
 
 
Jun 11 23:08:39.250: //4032/80470C400700/SIP/Msg/ccsipDisplayMsg:
Received: 
SIP/2.0 100 Trying

Via: SIP/2.0/UDP PUBLIC_IP:5060;branch=z9hG4bK1CC3F08;received=PUBLIC_IP

From: "7001" <sip:7001@PUBLIC_IP>;tag=42E873C4-1FF0

To: <sip:4023622211@chicago.voip.ms>

Call-ID: 36D5630F-B35111E1-858D874F-1E64976B@dns.name.of.your.device

CSeq: 102 INVITE

User-Agent: VoIPMS/SERAST

Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO

Supported: replaces

Contact: <sip:4023622211@64.120.22.242>

Content-Length: 0

 
 
 
Jun 11 23:08:44.493: //4032/80470C400700/SIP/Msg/ccsipDisplayMsg:
Received: 
SIP/2.0 183 Session Progress

Via: SIP/2.0/UDP PUBLIC_IP:5060;branch=z9hG4bK1CC3F08;received=PUBLIC_IP

From: "7001" <sip:7001@PUBLIC_IP>;tag=42E873C4-1FF0

To: <sip:4023622211@chicago.voip.ms>;tag=as7ca65274

Call-ID: 36D5630F-B35111E1-858D874F-1E64976B@dns.name.of.your.device

CSeq: 102 INVITE

User-Agent: VoIPMS/SERAST

Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO

Supported: replaces

Contact: <sip:4023622211@64.120.22.242>

Content-Type: application/sdp

Content-Length: 287

 
 
v=0

o=root 3036 3036 IN IP4 64.120.22.242

s=session

c=IN IP4 64.120.22.242

t=0 0

m=audio 11722 RTP/AVP 0 18 101

a=rtpmap:0 PCMU/8000

a=rtpmap:18 G729/8000

a=fmtp:18 annexb=no

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-16

a=silenceSupp:off - - - -

a=ptime:20

a=sendrecv

 
Jun 11 23:08:55.776: //4032/80470C400700/SIP/Msg/ccsipDisplayMsg:
Received: 
SIP/2.0 200 OK

Via: SIP/2.0/UDP PUBLIC_IP:5060;branch=z9hG4bK1CC3F08;received=PUBLIC_IP

From: "7001" <sip:7001@PUBLIC_IP>;tag=42E873C4-1FF0

To: <sip:4023622211@chicago.voip.ms>;tag=as7ca65274

Call-ID: 36D5630F-B35111E1-858D874F-1E64976B@dns.name.of.your.device

CSeq: 102 INVITE

User-Agent: VoIPMS/SERAST

Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO

Supported: replaces

Contact: <sip:4023622211@64.120.22.242>

Content-Type: application/sdp

Content-Length: 287

 
 
v=0

o=root 3036 3037 IN IP4 64.120.22.242

s=session

c=IN IP4 64.120.22.242

t=0 0

m=audio 11722 RTP/AVP 0 18 101

a=rtpmap:0 PCMU/8000

a=rtpmap:18 G729/8000

a=fmtp:18 annexb=no

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-16

a=silenceSupp:off - - - -

a=ptime:20

a=sendrecv

 
Jun 11 23:08:55.792: //4032/80470C400700/SIP/Msg/ccsipDisplayMsg:
Sent: 
ACK sip:4023622211@64.120.22.242:5060 SIP/2.0

Via: SIP/2.0/UDP PUBLIC_IP:5060;branch=z9hG4bK1CC41C1F

From: "7001" <sip:7001@PUBLIC_IP>;tag=42E873C4-1FF0

To: <sip:4023622211@chicago.voip.ms>;tag=as7ca65274

Date: Mon, 11 Jun 2012 23:08:39 GMT

Call-ID: 36D5630F-B35111E1-858D874F-1E64976B@dns.name.of.your.device

Max-Forwards: 70

CSeq: 102 ACK

Proxy-Authorization: Digest username="141513",realm="chicago.voip.ms",uri="sip:4023622211@chicago.voip.ms:5060",response="48d595b26162c614cd77f2b1c3c2f4a0",nonce="4778b4e0",algorithm=MD5

Allow-Events: telephone-event

Content-Type: application/sdp

Content-Disposition: session;handling=required

Content-Length: 270

 
 
v=0

o=CiscoSystemsSIP-GW-UserAgent 6908 5879 IN IP4 PUBLIC_IP

s=SIP Call

c=IN IP4 PUBLIC_IP

t=0 0

m=audio 17266 RTP/AVP 18 101

c=IN IP4 PUBLIC_IP

a=rtpmap:18 G729/8000

a=fmtp:18 annexb=no

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-16

a=ptime:20

 
Jun 11 23:09:07.879: //4032/80470C400700/SIP/Msg/ccsipDisplayMsg:
Sent: 
BYE sip:4023622211@64.120.22.242:5060 SIP/2.0

Via: SIP/2.0/UDP PUBLIC_IP:5060;branch=z9hG4bK1CC526CC

From: "7001" <sip:7001@PUBLIC_IP>;tag=42E873C4-1FF0

To: <sip:4023622211@chicago.voip.ms>;tag=as7ca65274

Date: Mon, 11 Jun 2012 23:08:39 GMT

Call-ID: 36D5630F-B35111E1-858D874F-1E64976B@dns.name.of.your.device

User-Agent: Cisco-SIPGateway/IOS-12.x

Max-Forwards: 70

P-Preferred-Identity: "7001" <sip:7001@dns.name.of.your.device>

Timestamp: 1339456147

CSeq: 103 BYE

Proxy-Authorization: Digest username="141513",realm="chicago.voip.ms",uri="sip:4023622211@64.120.22.242:5060",response="f3815093b9b277720feda2fbfb22ab7a",nonce="4778b4e0",algorithm=MD5

Reason: Q.850;cause=16

P-RTP-Stat: PS=602,OS=12040,PR=604,OR=12080,PL=0,JI=0,LA=0,DU=12

Content-Length: 0

 
 
 
Jun 11 23:09:07.891: //4032/80470C400700/SIP/Msg/ccsipDisplayMsg:
Received: 
SIP/2.0 200 OK

Via: SIP/2.0/UDP PUBLIC_IP:5060;branch=z9hG4bK1CC526CC;received=PUBLIC_IP

From: "7001" <sip:7001@PUBLIC_IP>;tag=42E873C4-1FF0

To: <sip:4023622211@chicago.voip.ms>;tag=as7ca65274

Call-ID: 36D5630F-B35111E1-858D874F-1E64976B@dns.name.of.your.device

CSeq: 103 BYE

User-Agent: VoIPMS/SERAST

Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO

Supported: replaces

Content-Length: 0

drkat

Looking at the SIP traces, I see the 183 Session in Progress then within 10ms we're seeing a 200 OK indicating the call is connected... Since the SIP provider is sending the 183 session in progress - with sdp.. I'd see if we could grab a trace on the sdp to see if there is anything there for ringing..

not sure if we could force them to send a 180 and generate ringback locally?

i think there is a block 183 sdp command, but not sure the behavior.. but worth a shot

JZegers

tried block 183 sdp present and block 183 sdp absent under voice services voip then sip command, no joy

JZegers

Also, this is on a CUCM server using a 2801 as a H323 gateway to the sip trunk

drkat

oh.. do you get an alerting in the q931?

drkat

check this out see if it works - seems to be a common issue with CUCM {h323} VG {SIP} Telco

https://supportforums.cisco.com/thread/2084500

JZegers

i tried no h225 h245-address on-connect under voice services voip, h323 and no dice

JZegers

Copy of my current config:

version 15.1
service timestamps debug datetime msec
service timestamps log datetime msec
service password-encryption
!
hostname 2801CME
!
boot-start-marker
boot-end-marker
!
!
logging buffered 4096 warnings
!
no aaa new-model
clock timezone NEB -6 0
dot11 syslog
ip source-route
!
!
!
!
!
ip cef
ip domain name xxx
ip name-server 4.2.2.2
ip name-server 8.8.8.8
no ipv6 cef
multilink bundle-name authenticated
!
!
!
!
!
!
voice service voip
 ip address trusted list
  ipv4 64.120.22.242 255.255.255.255
 gcid
 clid substitute name
 allow-connections h323 to h323
 allow-connections h323 to sip
 allow-connections sip to h323
 allow-connections sip to sip
 no supplementary-service sip moved-temporarily
 no supplementary-service sip refer
 h323
  no call service stop
 sip
  bind control source-interface FastEthernet0/1
  bind media source-interface FastEthernet0/1
  e911
  registrar server expires max 250 min 200
  transport switch udp tcp
  asserted-id ppi
  localhost dns:dns.name.of.your.device
  no update-callerid
  midcall-signaling passthru
  no call service stop
!
voice class h323 1
  h225 timeout tcp establish 2
  h225 timeout setup 2
!
!
!
!
!
voice-card 0
!
crypto pki token default removal timeout 0
!
crypto pki trustpoint TP-self-signed-18735116
 enrollment selfsigned
 subject-name cn=IOS-Self-Signed-Certificate-18735116
 revocation-check none
!
!
crypto pki certificate chain TP-self-signed-18735116
 certificate self-signed 01
  30820227 30820190 A0030201 02020101 300D0609 2A864886 F70D0101 04050030 
  2F312D30 2B060355 04031324 494F532D 53656C66 2D536967 6E65642D 43657274 
  69666963 6174652D 31383733 35313136 301E170D 31323035 32393233 32323333 
  5A170D32 30303130 31303030 3030305A 302F312D 302B0603 55040313 24494F53 
  2D53656C 662D5369 676E6564 2D436572 74696669 63617465 2D313837 33353131 
  3630819F 300D0609 2A864886 F70D0101 01050003 818D0030 81890281 8100B909 
  F615AF67 49D16255 70F92E10 CD7AF685 B7B24CD5 A0C125E0 8F65C1C9 BDF22D92 
  428380D0 28EAAD35 7C3C1DF8 FA39F141 AF6D08BC 8AFB0864 2E99AC4F B52B5893 
  1F2B247A FCC232FA B7636031 4881803C 541E6469 50173CDC CF95157C ADC56B2A 
  0C7EB16F 1CF29406 9B37C1FE 4B6BF653 506AD22D 91FE0860 DAB94232 ADC70203 
  010001A3 53305130 0F060355 1D130101 FF040530 030101FF 301F0603 551D2304 
  18301680 148A98A7 2C399DD7 B4D9A618 E08321A4 DC07E347 8D301D06 03551D0E 
  04160414 8A98A72C 399DD7B4 D9A618E0 8321A4DC 07E3478D 300D0609 2A864886 
  F70D0101 04050003 81810051 553392F1 2770F0D1 C49B06DE E0BC4A73 4099355C 
  D0895E6E 9791586D 6AB0CFD8 7E187028 508C3E16 EBF81FC4 2D8B2FFF 0FBB1C90 
  E919EF83 BD63FE1C F2974B23 013D68D7 C2CF336F D2AA460C EA983366 3BAE5F0E 
  F1F2ACF2 95E7B286 F1607CAD 2DB5390E ED9FC40A 28F2D6D3 4D9C38A6 CB6C3F1A 
  11998A38 7457BD6E 493B2E
   quit
!
!
license udi pid CISCO2801 sn FCZ101921S8
!
!
ip ssh version 1
!
!
!
!
!
interface FastEthernet0/0
 ip address 172.16.0.254 255.255.255.0
 duplex auto
 speed auto
 h323-gateway voip interface
 h323-gateway voip bind srcaddr 172.16.0.254
!
interface FastEthernet0/1
 ip address xxxx 255.255.255.0
 duplex auto
 speed auto
!
ip forward-protocol nd
!
!
no ip http server
ip http authentication local
ip http secure-server
ip route 0.0.0.0 0.0.0.0 69.80.120.1
ip route 172.16.1.0 255.255.255.0 172.16.0.1
ip route 192.168.9.0 255.255.255.0 172.16.0.1
ip route 192.168.254.0 255.255.255.0 172.16.0.1
!
logging esm config
!
snmp-server community CACTI RO
snmp-server chassis-id 2801CME
!
!
control-plane
!
!
!
!
mgcp profile default
!
!
dial-peer voice 1 voip
 session target ipv4:172.16.0.253
 incoming called-number .
 voice-class sip asserted-id ppi
 no voice-class sip block 180
 no voice-class sip block 183
 no voice-class sip block 181
 no voice-class sip pass-thru headers
 no voice-class sip pass-thru content unsupp
 no voice-class sip pass-thru content sdp
 dtmf-relay rtp-nte
!
dial-peer voice 2 voip
 destination-pattern .
 session protocol sipv2
 session target sip-server
 session transport udp
 voice-class sip asserted-id ppi
 no voice-class sip block 180
 no voice-class sip block 183
 no voice-class sip block 181
 voice-class sip pass-thru headers unsupp
 voice-class sip pass-thru content unsupp
 voice-class sip pass-thru content sdp
 dtmf-relay rtp-nte
!
dial-peer voice 3 voip
 destination-pattern 4028581340
 session target ipv4:172.16.0.253
 voice-class h323 1
!
!
gateway 
 timer receive-rtp 1200
!
sip-ua 
 credentials username xxx password 7 xxx realm voip.ms
 authentication username xxx password 7 xxx
 registrar 1 dns:chicago.voip.ms expires 200
 sip-server dns:chicago.voip.ms
!
!
!
line con 0
line aux 0
line vty 0 4
 login local
 transport input ssh
!
scheduler allocate 20000 1000
ntp master
end
2801CME#

drkat

I had read something about doing the changes in CUCM and not the VG - I thought there were attachments to that cisco post

can you run wireshark capture

JZegers

Ill see what i can do. Any other debugging options i should run on the router?

shodown

I think you maybe having some sip normalization problems.

Unified Border Element (CUBE) Session Initiation Protocol (SIP) Normalization with SIP Profiles Configuration Example [Cisco Unified Border Element] - Cisco Systems

drkat

good call.

august263

Hi All,

Was the above problem resolved, I'm having the same issue as Jzegers.

Thanks

August263

JZegers

Not yet

JZegers

So if i want to convert it to a sip trunk to my cucm, so it goes sip provider > 2801 > sip trunk to cucm, how do i get my sip connection bound on both FE ports? 0/0 is on the public IP address to provider and 0/1 is private IP. If i bind it to the 0/1 interface my trunk won't register with the provider. How do you get around this?

JZegers

i fixed this by converting from an h323 trunk to my CUBE to a sip connection, so its SIP the whole way through and using annunciator