UC520 SIP Trunk Hairpin issue with manual Call Transfer

rawsonfang · ‎10-18-2010

Have UC520 and use SIP trunk to ITSP for PSTN connection.Both inbound and outbound call works fine.

Have issue with hairpin issue, when the PSTN user call the inbound DID via SIP trunking, IP phone extension could take the call and transfer to other IP phone in other internal extensions, but if it fails if this extension need transfer the call to outside Cell phone via SIP trunking to PSTN.

Following is call flow, IP phone receives call from PSTN, press softkey " Transfer", get dial tone, and dial the outside cell phone at PSTN, cell phone ring and accepts call, press " Transfer" again on the IP phone, the call orginator and cell phone user could not hear audio at both end with silience. and it appears that UC520 still have both call active, but could not bridge the 2 calls together.

Any idea?

Thanks in advance.

Scott Martin · ‎10-18-2010

I'm encountering this too with another setup using an AA diverting offsite to a landline/mobile over a SIP trunk hairpin.

ADAM CRISP · ‎10-20-2010

Hi,

There are a few ways of solving this one.

The easiest way to fix it is to stop the UC520 from asking the Service provider to join two calls together. Most SP's don't support this anyway because of billing considerations (well we we don't anyway). This will force the UC to keep involved in the ongoing transferred call.

In both the outgoing and incomming dial-peers for your service provider, please disable the SIP REFER method.

You can do this from the command line by adding the line no supplementary-service sip refer

Here's an example of my incoming dial-peer and an outgoing dial-peer.

UC520#show run | sec dial-peer voice 999
dial-peer voice 999 voip
description "incoming dial-peer from VoIP.co.uk"
translation-profile incoming incoming_sip
incoming called-number AAA+
voice-class codec 1
dtmf-relay rtp-nte
no vad
no supplementary-service sip refer
!
UC520#show run | sec dial-peer voice 1001
dial-peer voice 1001 voip
description "outgoing dial-peer to VoIP.co.uk for UK fixed line starting 01"
destination-pattern 01.........
session protocol sipv2
session target sip-server
voice-class codec 1
dtmf-relay rtp-nte
no vad
no supplementary-service sip refer
!

If you're using CCA - it's a bit of a nightmare finding all your outgoing dial-peers - but try typing "show dial-peer voice summary" and look for the dial-peers which go thorough to the "sip-server" - yours may be configured up differently

thanks

Adam

Scott Martin · ‎10-20-2010

Hi Adam,

Thanks for the info - however I already have the following line in place (as per the standard config):

voice service voip
allow-connections h323 to h323
allow-connections h323 to sip
allow-connections sip to h323
allow-connections sip to sip
supplementary-service h450.12
no supplementary-service sip moved-temporarily
no supplementary-service sip refer

As a top level system command, shouldn't this override any dial-peer in use on these calls and make them unnecessary?

I will try applying to some test dial-peers however there are many as you suggest.

I am also working with TAC on this who have suggested a codec mismatch issue - I will try both solutions and let you know what works.

Regards,

Scott

Scott Martin · ‎10-20-2010

And to follow up, setting the codec didn't work (as I expected it wouldn't - it's in a fully g.711u standard config).

Setting these commands on the dial-peers had no effect either - as this was already in place under the voice service voip config.

I have referred back to TAC for further investigation.

rawsonfang · ‎10-21-2010

Hi Scott,

I have following same troubleshooting approach, and no luck either, please keep me update with your progress with TAC. Thanks

Steven Holl · ‎10-21-2010

What is the TAC SR number?

Can you get:

debug voip ccapi inout

debug ccsip mess

Also post a full output of 'sh run'.

I saw this occur yesterday on someone's UC500 due to the inbound leg negotiating g729, and the outbound peer being g711. But you already mentioned that you are g711ulaw for everything, so it must be something else (perhaps CLID or diversion header presentation).

Scott Martin · ‎10-21-2010

Hi Steven,

I'm working with the TAC on SR# 615772071 - with a very helpful engineer from Europe (out of our hours - but that actually works in this instance).

After much join diagnosis until midnight last night, it was determined that the issues are with dial-peers and the SIP INVITEs showing incorrect CLID information - regardless of forcing a CLID output with a voice class command - which IOS is ignoring. The provider is therefore rejecting the SIP calls as they are expecting oursipnumber@sip.provider.com on outbound calls, but are getting Anonymous@sip.provider.com and various other erroneous SIP headers. There are other cases where it is trying to pass the incoming CLID to the outgoing call, ignoring the fact the dial-plan tells it otherwise.

It seems that the issue is only present when the call traverses the CUE service-module, and all other calls are presenting correctly.

This may in face be a bug in the SIP implementation in IOS - but further analysis is being done, which I will continue to work on it this evening with the engineer. He suggested we may also try newer IOS/CME version. So much for these foolproof software packs...

This is certainly not a codec issue - as I mentioned, all are running in g.711ulaw.

It is also worth noting that this configuration was originally developed entirely with CCA, the 'Generic SIP Trunk' template and the in-built Australian dial-plan, which may in fact be contributing to the issue.

I should have some more details this evening and will post the solution once it is found.

Cheers,

Scott Martin

Steven Holl · ‎10-22-2010

Scott,

I looked at the debugs in the SR. For the anonymous issue, I see the INVITE from the provider come in with the ANI of anonymous, so that's the provider sending *us* a restricted CLID, right?

040015: Oct 22 21:36:56.083: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
INVITE sip:0290435450@10.10.10.4:5060 SIP/2.0
Via: SIP/2.0/UDP 203.2.134.1:5060;branch=z9hG4bKdt15rc209000rggmf681.1
From: "Anonymous";tag=1725871870-1287743872484-

203.2.134.1 is your provider right? The debugs I'm looking at on the SR, I don't have any outbound INVITEs at all, actually.

If we were sending anonymous out to the provider, that's typically a result of privacy settings, but I don't see any debugs for outbound INVITEs to make conclusions on that, nor on the hairpin transfer.

I see the bye-also transfer from CUE trigger, and transfer attempt match peer 1021 out to your PSTN number ending in 381 (don't want to post the full number here), but never see the INVITE go out. The debugs were collected to the console, though, so the INVITE may have went out, but just never showed up in the debugs. Can you recollect with:

Router(config)# service sequence
Router(config)# service timestamps debug datetime msec
Router(config)# logging buffered 10000000 7
Router(config)# no logging con
Router(config)# no logging mon
Router(config)# voice iec syslog

Router# term len 0

Router# sh logg

Also, there was mention of you hitting SIP-BADPAIR messages in the notes, which are always a software bug.

Hope this helps some.

vcappucc · ‎10-22-2010

Hello Steve,

Please find a working log from the moment we send the DTMF to CUE (all this logs are from lab, replicating the affected system configuration) in which the call gets BYE BLINDLY transfered ( 2035411448-3715043807-2228983637-2879256568)

025762: *Oct 23 00:16:51.052: //-1/xxxxxxxxxxxx/SIP/Msg/sipDisplayBinaryData:
Sending: Binary Message Body
025763: *Oct 23 00:16:51.052: Content-Type: audio/telephone-event
09 80 00 64
025764: *Oct 23 00:16:51.052: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
NOTIFY sip:898@10.1.10.1:5060;transport=udp SIP/2.0
Via: SIP/2.0/UDP 10.1.10.2:5060;branch=z9hG4bK2F911C9
From: "anonymous" ;tag=D9635B0-763
To: <898>;tag=dsb576a120

Call-ID: A9B695F5-DD7111DF-87F08954-8CA2525F@10.1.10.2
CSeq: 103 NOTIFY
Max-Forwards: 70
Date: Sat, 23 Oct 2010 00:16:51 GMT
User-Agent: Cisco-SIPGateway/IOS-12.x
Event: telephone-event
Subscription-State: active
Contact: <10.1.10.2:5060>

Content-Type: audio/telephone-event
Content-Length: 4

^@.d
025765: *Oct 23 00:16:51.076: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
SIP/2.0 200 Ok
Via: SIP/2.0/UDP 10.1.10.2:5060;branch=z9hG4bK2F911C9

To: <898>;tag=dsb576a120
From: "anonymous" ;tag=D9635B0-763
Call-ID: A9B695F5-DD7111DF-87F08954-8CA2525F@10.1.10.2
CSeq: 103 NOTIFY
Content-Length: 0
Allow-Events: refer
Allow-Events: message-summary
Allow-Events: telephone-event

025766: *Oct 23 00:16:53.124: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
BYE sip:anonymous@10.1.10.2:5060 SIP/2.0
Via: SIP/2.0/UDP 10.1.10.1:5060;branch=z9hG4bKUInMHnvLxRspVEIkIULhyw~~4
Max-Forwards: 70
To: ;tag=D9635B0-763

From: <898>;tag=dsb576a120
Call-ID: A9B695F5-DD7111DF-87F08954-8CA2525F@10.1.10.2
CSeq: 2 BYE
Content-Length: 0
Also: <0201>
Allow: INVITE, BYE, CANCEL, ACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO
Cisco-Gcid: A9B695F5-DD7111DF-87F08954-8CA2525F@10.1.10.2

025767: *Oct 23 00:16:53.128: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.1.10.1:5060;branch=z9hG4bKUInMHnvLxRspVEIkIULhyw~~4
From: <898>;tag=dsb576a120
To: "anonymous" ;tag=D9635B0-763
Date: Sat, 23 Oct 2010 00:16:53 GMT

Call-ID: A9B695F5-DD7111DF-87F08954-8CA2525F@10.1.10.2
Server: Cisco-SIPGateway/IOS-12.x
CSeq: 2 BYE
Content-Length: 0

025768: *Oct 23 00:16:53.128: //-1/7951E9F884DB/DPM/dpMatchPeersCore:
   Calling Number=, Called Number=0201, Peer Info Type=DIALPEER_INFO_SPEECH
025769: *Oct 23 00:16:53.128: //-1/7951E9F884DB/DPM/dpMatchPeersCore:
   Match Rule=DP_MATCH_DEST; Called Number=0201
025770: *Oct 23 00:16:53.128: //-1/7951E9F884DB/DPM/dpMatchPeersCore:
   Result=Success(0) after DP_MATCH_DEST
025771: *Oct 23 00:16:53.128: //-1/7951E9F884DB/DPM/dpMatchSafModulePlugin:
   dialstring=0201, saf_enabled=0, saf_dndb_lookup=1, dp_result=0
025772: *Oct 23 00:16:53.128: //-1/7951E9F884DB/DPM/dpMatchPeersMoreArg:
   Result=SUCCESS(0)
   List of Matched Outgoing Dial-peer(s):
     1: Dial-peer Tag=1021
025773: *Oct 23 00:16:53.128: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Calling Number=, Called Number=221, Peer Info Type=DIALPEER_INFO_SPEECH
025774: *Oct 23 00:16:53.128: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Match Rule=DP_MATCH_DEST; Called Number=221
025775: *Oct 23 00:16:53.128: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   No Outgoing Dial-peer Is Matched; Result=NO_MATCH(-1)
025776: *Oct 23 00:16:53.128: //-1/xxxxxxxxxxxx/DPM/dpMatchSafModulePlugin:
   dialstring=NULL, saf_enabled=0, saf_dndb_lookup=0, dp_result=-1
025777: *Oct 23 00:16:53.128: //-1/xxxxxxxxxxxx/DPM/dpMatchPeers:
   Result=NO_MATCH(-1)
025778: *Oct 23 00:16:53.128: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Calling Number=, Called Number=0201, Peer Info Type=DIALPEER_INFO_SPEECH
025779: *Oct 23 00:16:53.128: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Match Rule=DP_MATCH_DEST; Called Number=0201
025780: *Oct 23 00:16:53.128: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Result=Success(0) after DP_MATCH_DEST
025781: *Oct 23 00:16:53.128: //-1/xxxxxxxxxxxx/DPM/dpMatchSafModulePlugin:
   dialstring=NULL, saf_enabled=0, saf_dndb_lookup=0, dp_result=0
025782: *Oct 23 00:16:53.128: //-1/xxxxxxxxxxxx/DPM/dpMatchPeers:
   Result=SUCCESS(0)
   List of Matched Outgoing Dial-peer(s):
     1: Dial-peer Tag=1021
025783: *Oct 23 00:16:53.132: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Calling Number=0201, Called Number=, Voice-Interface=0x0,
   Timeout=TRUE, Peer Encap Type=ENCAP_VOIP, Peer Search Type=PEER_TYPE_VOICE,
   Peer Info Type=DIALPEER_INFO_SPEECH
025784: *Oct 23 00:16:53.132: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Result=Success(0) after DP_MATCH_ORIGINATE; Incoming Dial-peer=1021
025785: *Oct 23 00:16:53.132: //-1/xxxxxxxxxxxx/DPM/dpMatchSafModulePlugin:
   dialstring=NULL, saf_enabled=0, saf_dndb_lookup=0, dp_result=0
025786: *Oct 23 00:16:53.132: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Calling Number=, Called Number=0201, Peer Info Type=DIALPEER_INFO_SPEECH
025787: *Oct 23 00:16:53.132: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Match Rule=DP_MATCH_DEST; Called Number=0201
025788: *Oct 23 00:16:53.132: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Result=Success(0) after DP_MATCH_DEST
025789: *Oct 23 00:16:53.132: //-1/xxxxxxxxxxxx/DPM/dpMatchSafModulePlugin:
   dialstring=0201, saf_enabled=0, saf_dndb_lookup=1, dp_result=0
025790: *Oct 23 00:16:53.132: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersMoreArg:
   Result=SUCCESS(0)
   List of Matched Outgoing Dial-peer(s):
     1: Dial-peer Tag=1021
025791: *Oct 23 00:16:53.132: //-1/7951E9F884DB/DPM/dpMatchPeersCore:
   Calling Number=, Called Number=0201, Peer Info Type=DIALPEER_INFO_SPEECH
025792: *Oct 23 00:16:53.132: //-1/7951E9F884DB/DPM/dpMatchPeersCore:
   Match Rule=DP_MATCH_DEST; Called Number=0201
025793: *Oct 23 00:16:53.132: //-1/7951E9F884DB/DPM/dpMatchPeersCore:
   Result=Success(0) after DP_MATCH_DEST
025794: *Oct 23 00:16:53.132: //-1/7951E9F884DB/DPM/dpMatchSafModulePlugin:
   dialstring=0201, saf_enabled=1, saf_dndb_lookup=1, dp_result=0
025795: *Oct 23 00:16:53.132: //-1/7951E9F884DB/DPM/dpMatchPeersMoreArg:
   Result=SUCCESS(0)
   List of Matched Outgoing Dial-peer(s):
     1: Dial-peer Tag=1021
025796: *Oct 23 00:16:53.132: //-1/7951E9F884DB/RXRULE/regxrule_stack_push_RegXruleNumInfo_internal: stack=0x85FE5508; count=3
025797: *Oct 23 00:16:53.132: //-1/7951E9F884DB/RXRULE/regxrule_profile_translate_internal: number=221 type=unknown plan=unknown numbertype=calling
025798: *Oct 23 00:16:53.132: //-1/7951E9F884DB/RXRULE/regxrule_profile_match_internal: Matched with rule 2 in ruleset 1111
025799: *Oct 23 00:16:53.132: //-1/7951E9F884DB/RXRULE/regxrule_profile_match_internal: Matched with rule 2 in ruleset 1111
025800: *Oct 23 00:16:53.132: //-1/7951E9F884DB/RXRULE/sed_subst: Successful substitution; pattern=221 matchPattern=.* replacePattern=100 replaced pattern=100
025801: *Oct 23 00:16:53.132: //-1/7951E9F884DB/RXRULE/regxrule_subst_num_type: Match Type = none, Replace Type = none Input Type = unknown
025802: *Oct 23 00:16:53.132: //-1/7951E9F884DB/RXRULE/regxrule_subst_num_plan: Match Plan = none, Replace Plan = none Input Plan = unknown
025803: *Oct 23 00:16:53.132: //-1/7951E9F884DB/RXRULE/regxrule_profile_translate_internal: xlt_number=100 xlt_type=unknown xlt_plan=unknown
025804: *Oct 23 00:16:53.132: //-1/7951E9F884DB/RXRULE/regxrule_profile_translate_internal: number=0201 type=unknown plan=unknown numbertype=called
025805: *Oct 23 00:16:53.132: //-1/7951E9F884DB/RXRULE/regxrule_profile_match_internal: Matched with rule 1 in ruleset 1112
025806: *Oct 23 00:16:53.132: //-1/7951E9F884DB/RXRULE/regxrule_profile_match_internal: Matched with rule 1 in ruleset 1112
025807: *Oct 23 00:16:53.132: //-1/7951E9F884DB/RXRULE/sed_subst: Successful substitution; pattern=0201 matchPattern=^0 replacePattern= replaced pattern=201
025808: *Oct 23 00:16:53.132: //-1/7951E9F884DB/RXRULE/regxrule_subst_num_type: Match Type = none, Replace Type = none Input Type = unknown
025809: *Oct 23 00:16:53.132: //-1/7951E9F884DB/RXRULE/regxrule_subst_num_plan: Match Plan = none, Replace Plan = none Input Plan = unknown
025810: *Oct 23 00:16:53.136: //-1/7951E9F884DB/RXRULE/regxrule_profile_translate_internal: xlt_number=201 xlt_type=unknown xlt_plan=unknown
025811: *Oct 23 00:16:53.136: //-1/7951E9F884DB/RXRULE/regxrule_profile_translate_internal: number= type=unknown plan=unknown numbertype=redirect-target
025812: *Oct 23 00:16:53.136: //-1/7951E9F884DB/RXRULE/regxrule_get_RegXrule: Invalid translation ruleset tag=0
025813: *Oct 23 00:16:53.136: //-1/7951E9F884DB/RXRULE/regxrule_profile_match_internal: Error: ruleset for redirect-target number not found
025814: *Oct 23 00:16:53.136: //-1/7951E9F884DB/RXRULE/regxrule_profile_translate_internal: No match: number= type=unknown plan=unknown
025815: *Oct 23 00:16:53.136: //-1/7951E9F884DB/RXRULE/regxrule_profile_translate_internal: number=898 type=unknown plan=unknown numbertype=redirect-called
025816: *Oct 23 00:16:53.136: //-1/7951E9F884DB/RXRULE/regxrule_get_RegXrule: Invalid translation ruleset tag=0
025817: *Oct 23 00:16:53.136: //-1/7951E9F884DB/RXRULE/regxrule_profile_match_internal: Error: ruleset for redirect-called number not found
025818: *Oct 23 00:16:53.136: //-1/7951E9F884DB/RXRULE/regxrule_profile_translate_internal: No match: number=898 type=unknown plan=unknown
025819: *Oct 23 00:16:53.136: //-1/7951E9F884DB/RXRULE/regxrule_dp_translate: calling_number=100 calling_octet=0x0
        called_number=201 called_octet=0x0
        redirect_number=898 redirect_type=0 redirect_plan=0     redirect_PI=0 redirect_SI=0
025820: *Oct 23 00:16:53.136: //-1/7951E9F884DB/RXRULE/regxrule_stack_pop_RegXruleNumInfo: stack=0x85FE5508; count=3
025821: *Oct 23 00:16:53.136: //-1/7951E9F884DB/RXRULE/regxrule_stack_pop_callinfo_internal: numinfo=0x884E0F7C
025822: *Oct 23 00:16:53.136: //-1/7951E9F884DB/RXRULE/regxrule_stack_push_RegXruleNumInfo_internal: stack=0x85FE5508; count=3
025823: *Oct 23 00:16:53.140: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
INVITE sip:201@192.168.23.2:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.13.1:5060;branch=z9hG4bK2FA537
Remote-Party-ID: "221" <100>;party=calling;screen=no;privacy=full
From: "anonymous" ;tag=D9644C8-0
To: <201>
Date: Sat, 23 Oct 2010 00:16:53 GMT
Call-ID: AC039383-DD7111DF-87F28954-8CA2525F@192.168.13.1

Supported: 100rel,timer,resource-priority,replaces,sdp-anat
Min-SE: 1800
Cisco-Guid: 2035411448-3715043807-2228983637-2879256568
User-Agent: Cisco-SIPGateway/IOS-12.x
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER
CSeq: 101 INVITE
Timestamp: 1287793013

Contact:
Expires: 180
Allow-Events: telephone-event
Max-Forwards: 68
Content-Type: application/sdp
Content-Disposition: session;handling=required
Content-Length: 247

v=0
o=CiscoSystemsSIP-GW-UserAgent 3472 1303 IN IP4 192.168.13.1
s=SIP Call
c=IN IP4 192.168.13.1
t=0 0
m=audio 16700 RTP/AVP 0 101
c=IN IP4 192.168.13.1
a=rtpmap:0 PCMU/8000

a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20

025824: *Oct 23 00:16:53.160: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.13.1:5060;branch=z9hG4bK2FA537

From: "anonymous" ;tag=D9644C8-0
To: <201>
Date: Sat, 23 Oct 2010 00:01:12 GMT
Call-ID: AC039383-DD7111DF-87F28954-8CA2525F@192.168.13.1
Timestamp: 1287793013
CSeq: 101 INVITE
Allow-Events: telephone-event
Server: Cisco-SIPGateway/IOS-12.x

Content-Length: 0

025825: *Oct 23 00:16:53.272: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 192.168.13.1:5060;branch=z9hG4bK2FA537
From: "anonymous" ;tag=D9644C8-0

To: <201>;tag=68E7E10-2536
Date: Sat, 23 Oct 2010 00:01:12 GMT
Call-ID: AC039383-DD7111DF-87F28954-8CA2525F@192.168.13.1
Timestamp: 1287793013
CSeq: 101 INVITE
Require: 100rel
RSeq: 2761
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER

Allow-Events: telephone-event
Remote-Party-ID: <201>;party=called;screen=no;privacy=off
Contact: <201>
Server: Cisco-SIPGateway/IOS-12.x
Content-Length: 0

025826: *Oct 23 00:16:53.272: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Calling Number=, Called Number=100, Peer Info Type=DIALPEER_INFO_SPEECH
025827: *Oct 23 00:16:53.272: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Match Rule=DP_MATCH_DEST; Called Number=100
025828: *Oct 23 00:16:53.272: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Result=Success(0) after DP_MATCH_DEST
025829: *Oct 23 00:16:53.272: //-1/xxxxxxxxxxxx/DPM/dpMatchSafModulePlugin:
   dialstring=NULL, saf_enabled=0, saf_dndb_lookup=0, dp_result=0
025830: *Oct 23 00:16:53.272: //-1/xxxxxxxxxxxx/DPM/dpMatchPeers:
   Result=SUCCESS(0)
   List of Matched Outgoing Dial-peer(s):
     1: Dial-peer Tag=20001
025831: *Oct 23 00:16:53.276: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Calling Number=, Called Number=201, Peer Info Type=DIALPEER_INFO_SPEECH
025832: *Oct 23 00:16:53.276: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   Match Rule=DP_MATCH_DEST; Called Number=201
025833: *Oct 23 00:16:53.276: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersCore:
   No Outgoing Dial-peer Is Matched; Result=NO_MATCH(-1)
025834: *Oct 23 00:16:53.276: //-1/xxxxxxxxxxxx/DPM/dpMatchSafModulePlugin:
   dialstring=NULL, saf_enabled=0, saf_dndb_lookup=0, dp_result=-1
025835: *Oct 23 00:16:53.276: //-1/xxxxxxxxxxxx/DPM/dpMatchPeers:
   Result=NO_MATCH(-1)
025836: *Oct 23 00:16:53.276: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
PRACK sip:201@192.168.23.2:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.13.1:5060;branch=z9hG4bK2FB2654
From: "anonymous" ;tag=D9644C8-0
To: <201>;tag=68E7E10-2536

Date: Sat, 23 Oct 2010 00:16:53 GMT
Call-ID: AC039383-DD7111DF-87F28954-8CA2525F@192.168.13.1
CSeq: 102 PRACK
RAck: 2761 101 INVITE
Allow-Events: telephone-event
Max-Forwards: 70
Content-Length: 0

025837: *Oct 23 00:16:53.280: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.13.1:5060;branch=z9hG4bK2FB2654
From: "anonymous" ;tag=D9644C8-0
To: <201>;tag=68E7E10-2536
Date: Sat, 23 Oct 2010 00:01:13 GMT

Call-ID: AC039383-DD7111DF-87F28954-8CA2525F@192.168.13.1
Server: Cisco-SIPGateway/IOS-12.x
CSeq: 102 PRACK
Content-Length: 0

025838: *Oct 23 00:16:54.780: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
SIP/2.0 486 Busy here
Via: SIP/2.0/UDP 192.168.13.1:5060;branch=z9hG4bK2FA537
From: "anonymous" ;tag=D9644C8-0
To: <201>;tag=68E7E10-2536
Date: Sat, 23 Oct 2010 00:01:13 GMT
Call-ID: AC039383-DD7111DF-87F28954-8CA2525F@192.168.13.1
Timestamp: 1287793013
CSeq: 101 INVITE
Allow-Events: telephone-event

Server: Cisco-SIPGateway/IOS-12.x
Reason: Q.850;cause=17
Content-Length: 0

025839: *Oct 23 00:16:54.780: //-1/7951E9F884DB/RXRULE/regxrule_stack_pop_callinfo_internal: numinfo=0x0
025840: *Oct 23 00:16:54.784: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Calling Number=0201, Called Number=, Voice-Interface=0x0,
   Timeout=TRUE, Peer Encap Type=ENCAP_VOIP, Peer Search Type=PEER_TYPE_VOICE,
   Peer Info Type=DIALPEER_INFO_SPEECH
025841: *Oct 23 00:16:54.784: //-1/xxxxxxxxxxxx/DPM/dpAssociateIncomingPeerCore:
   Result=Success(0) after DP_MATCH_ORIGINATE; Incoming Dial-peer=1021
025842: *Oct 23 00:16:54.784: //-1/xxxxxxxxxxxx/DPM/dpMatchSafModulePlugin:
   dialstring=NULL, saf_enabled=0, saf_dndb_lookup=0, dp_result=0
025843: *Oct 23 00:16:54.784: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
ACK sip:201@192.168.23.2:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.13.1:5060;branch=z9hG4bK2FA537
From: "anonymous" ;tag=D9644C8-0
To: <201>;tag=68E7E10-2536
Date: Sat, 23 Oct 2010 00:16:53 GMT
Call-ID: AC039383-DD7111DF-87F28954-8CA2525F@192.168.13.1
Max-Forwards: 70
CSeq: 101 ACK
Allow-Events: telephone-event

Content-Length: 0

R1#

I also think that the issue is based on the SIPBADIP Message as you indicate, we get when the call goes out

Thank you

Victor.-

Steven Holl · ‎10-24-2010

CCAPI debugs during this would shed more light. I'm thinking the anon ANI is a result of either the original ANI from the inbound PSTN call being anonymous, or the ANI being null on the outbound call leg back to the PSTN. The latter behavior is outlined here:

http://www.cisco.com/en/US/tech/tk652/tk701/technologies_tech_note09186a00807cc055.shtml

Does the issue occur if the original PSTN call inbound doesn't have anonymous for an ANI? It may be forwarding the original ANI for the outbound leg. Do you have a way to test with an inbound call that contains a legitimate ANI? (Or you could translate on the inbound SIP PSTN leg to a valid number for testing purposes.)

You should be able to apply either a translation profile, or a sip normalization profile to the outbound SIP leg to correct this outbound ANI, though.

Scott Martin · ‎10-24-2010

Steven,

I believe Victor already took CCAPI logs which should be in the case.

In regards to your CLID suggestion, this is already set in the configuration on:

voice translation-rule 1111

rule 15 /^...$/ /029043XXXX/ !XXXX inserted for privacy

voice translation-profile PSTN_Outgoing
translate calling 1111
translate called 1112
translate redirect-target 410
translate redirect-called 410

PSTN_Outgoing is then applied to all dial-peers as appropriate.

This is not the issue, as the dial-peers work perfectly regardless of CLID information when CUE is taken out of the mix. The issue is present whether the PSTN inbound presents CLID or not.

If you require additional logs, let me know and I will produce and upload.

Based on the above configuration, ALL calls leaving the CME should have the SIP trunk number (which they do), however if the call goes through CUE, they are not hitting this translation profile.

Steven Holl · ‎10-25-2010

CCAPI wasn't on the debugs posted in this thread (and the debugs on the SR had dropped messages and didn't contain all SIP debugs). By looking at both separately, it looks like the reason anonymous goes out as an ANI on the outbound leg is a result of anonymous coming in on the original leg. I don't know where to look for the debugs of a working call forwarding off the phone, to confirm this, though.

The call comes in peer 3000, which only has 'Main_In-AA_Called_4' applied to it, and doesn't touch the ANI, so anonymous will propagate through on the outbound transfer leg.

Rule 15 will only take effect for calls with an ANI of 3 digits when matching 1021 outbound. The calls from CUE are going out with a null ANI, so it wouldn't apply to that scenario, and we're not going to rewrite the ANI.

Try doing this, which I think should rewrite the ANI to the main number if it comes in null:

voice translation-rule 1111
 rule 15 /^...$/ /029043XXXX/  !XXXX inserted for privacy
 rule 16 /^$/ /029043XXXX/  !XXXX inserted for privacy

I haven't tried using a null string to match an ANI that comes across as 'anonymous' but I think it will work. If that doesn't, use a match string of /^.*$/ which will match everything, and see how that fares. When you transfer from an IP phone, I'm guessing the ANI is properly re-written to a three digit extension, and then hits this pattern and translates. I'd need debugs for this working scenario to confirm that, though.

Otherwise, I'd collect the follwong to the logging buffer, for both a call forwarded off of CUE, and for a call forwarded off the phone. We should be able to identify the deviation there:

debug voip ccapi inout

debug ccsip all

debug voip translation

debug voip dialpeer all

Collect with the method as mentioned on Oct 22, 2010 12:50 PM.

Scott Martin · ‎10-25-2010

Hi Steven,

I can confirm that neither of the translation-rules work to resolve the issue. I will collect debug logs and post them to the case in the next couple of hours, in addition to trying the solution proposed by Victor Cappuccio in the TAC SR.

I tried:

rule 15 /^$/ /029043XXXX/

-and-

rule 15 /^.$/ /029043XXXX/

as suggested - with no effect. Actually the first suggestion stopped all outbound calls, but thats another matter.

Also, on the UC500, the rules only go up to 15 - so I improvised, but regardless, it doesn't work.

Again, I reiterate that the issue is only present when the call is coming from CUE - my outgoing dial-peers and translation-rules work perfectly otherwise.

Kind Regards,

Scott Martin

Scott Martin · ‎10-25-2010

FYI: Debugs now in the TAC case for both the translation-rule and loopback-dn configurations, neither worked.