ATT SIP inbound trouble with porting numbers 1

[cdiris]

I have a customer currently on ATT Fiber with SIP. Their inbound and outbound calls are working fine. They have a PRI connection on this IP Office 500V2 9.1.3 system as well. They are porting all the PRI numbers over to the SIP connection. When ATT tested the numbers through the ATT network before porting some numbers worked and some didn't. A 404 not found is sent back from the IP Office so ATT determined the IPO was programmed incorrectly. There is no difference in programming seen between the numbers that work and the ones that don't. I took monitor traces of a non-working number and of a working number (one that is current--not a porting number). The only differences I see are that the non-working number does not have an IP address in the Caller ID on the invite and also that the Endpoint:Lookup Call Route right before the 404 error has called_party=5227 instead of a 10 digit number. I'll post them below in case someone can glean more detailed info on this problem than I could (the traces are fairly small). Numbers have been changed to protect the innocent. The port has been rescheduled so I am hoping to have some data I can bring to ATT soon or something found to change in the config. I only have occasional access to the config from the customer IT but I can recommend changes. Again, all SIP numbers are currently working fine--it is roughly half of the porting numbers that don't work. Various config changes have been tried without any change. Thanks!

Not working trace:
12:29:33 1077278756mS SIP Rx: UDP 12.194.XXX.5:5060 -> 192.168.XXX.30:5060
INVITE sip:8XXX585227@192.168.XXX.30:5060 SIP/2.0
Via: SIP/2.0/UDP 12.194.XXX.5:5060;branch=z9hG4bK4k0vr53080p0nf0jp5s0.1
From: "John Nameless" <sip:7XXX522939@12.194.XXX.5:5060>;tag=16360360775195493_c3b04.1.3.1452147759681.0_2278648_4503049
To: <sip:8XXX585227@192.168.XXX.30>
Call-ID: 8956644171024899@c3b04_1_3
CSeq: 2 INVITE
P-Asserted-Identity: "John Nameless" <sip:7XXX522939@12.194.XXX.5>
Remote-Party-ID: "John Nameless" <sip:7XXX522939@12.194.XXX.5>;party=calling;id-type=subscriber;privacy=off
Allow: INVITE,ACK,CANCEL,BYE,INFO,PRACK
Max-Forwards: 61
Contact: <sip:12.194.XXX.5:5060;transport=udp>
Content-Length: 271
Content-Type: application/sdp

v=0
o=- 2746027946 2746027946 IN IP4 12.194.XXX.5
s=Polycom IP Phone
c=IN IP4 12.194.XXX.5
t=0 0
a=sendrecv
m=audio 28780 RTP/AVP 18 0 8 101
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
12:29:33 1077278759mS CMCallEvt: 0000000000000000 0.438117.0 -1 BaseEP: NEW CMEndpoint f1639af4 TOTAL NOW=7 CALL_LIST=3
12:29:33 1077278763mS SIP Tx: UDP 192.168.XXX.30:5060 -> 12.194.XXX.5:5060
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 12.194.XXX.5:5060;branch=z9hG4bK4k0vr53080p0nf0jp5s0.1
From: "John Nameless" <sip:7XXX522939@12.194.XXX.5:5060>;tag=16360360775195493_c3b04.1.3.1452147759681.0_2278648_4503049
Call-ID: 8956644171024899@c3b04_1_3
CSeq: 2 INVITE
Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,INFO,NOTIFY
Supported: timer
Server: IP Office 9.1.3.0 build 120
To: <sip:8XXX585227@192.168.XXX.30>;tag=ff74fd2f89089d9f
Content-Length: 0

12:29:33 1077278765mS CMCallEvt: CREATE CALL:105582 (f1650ccc)
12:29:33 1077278766mS CMCallEvt: 0000000000000000 0.438118.0 -1 BaseEP: NEW CMEndpoint f16444c8 TOTAL NOW=8 CALL_LIST=3
12:29:33 1077278769mS CMCallEvt: 0a640c150006af65 17.438117.1 105582 SIPTrunk Endpoint: StateChange: END=A CMCSIdle->CMCSDialInitiated
12:29:33 1077278769mS CMTARGET: 0a640c150006af65 17.438117.1 105582 SIPTrunk Endpoint: LOOKUP CALL ROUTE: GID=7100 type=100 called_party=5227 sub= calling=7XXX522939@12.194.XXX.5 dir=in complete=1 ses=0
12:29:33 1077278773mS SIP Tx: UDP 192.168.XXX.30:5060 -> 12.194.XXX.5:5060
SIP/2.0 404 Not Found
Via: SIP/2.0/UDP 12.194.XXX.5:5060;branch=z9hG4bK4k0vr53080p0nf0jp5s0.1
From: "John Nameless" <sip:7XXX522939@12.194.XXX.5:5060>;tag=16360360775195493_c3b04.1.3.1452147759681.0_2278648_4503049
Call-ID: 8956644171024899@c3b04_1_3
CSeq: 2 INVITE
Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,INFO,NOTIFY
Supported: timer
Server: IP Office 9.1.3.0 build 120
Reason: Q.850;cause=1;text="Unallocated (unassigned) number"
To: <sip:8XXX585227@192.168.XXX.30>;tag=ff74fd2f89089d9f
Content-Length: 0
*****************************
Working Trace:
12:37:59 1077785776mS SIP Rx: UDP 12.194.XXX.5:5060 -> 192.168.XXX.30:5060
INVITE sip:8XXXX87871@192.168.XXX.30:5060 SIP/2.0
Via: SIP/2.0/UDP 12.194.XXX.5:5060;branch=z9hG4bKqgq6301080ogof0jp5s0.1
From: "John Nameless" <sip:7XXX522939@12.194.XXX.5:5060>;tag=567948102643999_c2b06.1.2.1421996196436.0_31099878_61720834
To: <sip:8XXXX87871@192.168.XXX.30>
Call-ID: 5509373937432032@12.114.58.38
CSeq: 2 INVITE
P-Asserted-Identity: "John Nameless" <sip:7XXX522939@12.194.XXX.5>
Remote-Party-ID: "John Nameless" <sip:7XXX522939@12.194.XXX.5>;party=calling;id-type=subscriber;privacy=off
Allow: INVITE,ACK,CANCEL,BYE,INFO,PRACK
Max-Forwards: 61
Contact: <sip:12.194.XXX.5:5060;transport=udp>
Content-Length: 271
Content-Type: application/sdp

v=0
o=- 2746534870 2746534870 IN IP4 12.194.XXX.5
s=Polycom IP Phone
c=IN IP4 12.194.XXX.5
t=0 0
a=sendrecv
m=audio 29416 RTP/AVP 18 0 8 101
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
12:37:59 1077785780mS CMCallEvt: 0000000000000000 0.438178.0 -1 BaseEP: NEW CMEndpoint f1615c78 TOTAL NOW=11 CALL_LIST=5
12:37:59 1077785783mS SIP Tx: UDP 192.168.XXX.30:5060 -> 12.194.XXX.5:5060
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 12.194.XXX.5:5060;branch=z9hG4bKqgq6301080ogof0jp5s0.1
From: "John Nameless" <sip:7XXX522939@12.194.XXX.5:5060>;tag=567948102643999_c2b06.1.2.1421996196436.0_31099878_61720834
Call-ID: 5509373937432032@12.114.58.38
CSeq: 2 INVITE
Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,INFO,NOTIFY
Supported: timer
Server: IP Office 9.1.3.0 build 120
To: <sip:8XXXX87871@192.168.XXX.30>;tag=40eebb191d735822
Content-Length: 0

12:37:59 1077785786mS CMCallEvt: CREATE CALL:105596 (f1885fb0)
12:37:59 1077785786mS CMCallEvt: 0000000000000000 0.438179.0 -1 BaseEP: NEW CMEndpoint f1931b40 TOTAL NOW=12 CALL_LIST=5
12:37:59 1077785789mS CMCallEvt: 0a640c150006afa2 17.438178.1 105596 SIPTrunk Endpoint: StateChange: END=A CMCSIdle->CMCSDialInitiated
12:37:59 1077785789mS CMTARGET: 0a640c150006afa2 17.438178.1 105596 SIPTrunk Endpoint: LOOKUP CALL ROUTE: GID=0 type=100 called_party=8317587871 sub= calling=7XXX522939@12.194.XXX.5 dir=in complete=1 ses=0
12:37:59 1077785789mS CMTARGET: 0a640c150006afa2 17.438178.1 105596 SIPTrunk Endpoint: SET BESTMATCH: length 0 vs -1 match= dest=MainStreetSt
12:37:59 1077785790mS CMCallEvt: Priority hike: call 105596 priority 0->1
12:37:59 1077785790mS CMTARGET: 0a640c150006afa2 17.438178.1 105596 SIPTrunk Endpoint: LOOKUP ICR: DDI=8317587871 CGPN=7XXX522939@12.194.XXX.5 (Destination MainStreetSt ) => CDPN=MainStreetSt
12:37:59 1077785790mS CMTARGET: 0a640c150006afa2 17.438178.1 105596 SIPTrunk Endpoint: ADD TARGET (N): number=MainStreetSt type=100 depth=1 nobar=1 setorig=1 ses=0
12:37:59 1077785790mS CMTARGET: 0a640c150006afa2 17.438178.1 105596 SIPTrunk Endpoint: HG(MainStreetSt,7800,10.100.12.21) Requires Routing To Master(1). IsLocalExecutive(1)
12:37:59 1077785790mS CMTARGET: 0a640c150006afa2 17.438178.1 105596 SIPTrunk Endpoint: HG call targeting occuring here
12:37:59 1077785790mS CMTARGET: 0a640c150006afa2 17.438178.1 105596 SIPTrunk Endpoint: PrimeForHGTarget: MainStreetSt setorig=1 recall=0 resetExtnVars 1
12:37:59 1077785790mS CMCallEvt: Priority hike: call 105596 priority 1->5
12:37:59 1077785790mS CMTARGET: 0a640c150006afa2 17.438178.1 105596 SIPTrunk Endpoint: AddHGTarget MainStreetSt (depth=1) allowq=1 type=CMNTypeDefault
12:37:59 1077785791mS CMCallEvt: 0000000000000000 0.438180.0 -1 BaseEP: NEW CMEndpoint f18e88b4 TOTAL NOW=13 CALL_LIST=6
12:37:59 1077785791mS CMTARGET: 0a640c150006afa2 17.438178.1 105596 SIPTrunk Endpoint: AddHGTargetRingGroup MainStreetSt starting at 0
12:37:59 1077785791mS CMTARGET: 0a640c150006afa2 17.438178.1 105596 SIPTrunk Endpoint: ADD USER: PlaceMain depth=2 disallow_cw=0 dnd=0 real_call=1 group_call=1 type(CMNTypeDefault) incl(0x0) excpt(0x3c), allow_redir(1) remote=00000000 simult 0 (0)
12:37:59 1077785792mS CMMap: a=6.17 b=0.0 Mapper::AllocateCodec allocated CMRTVocoder(f54f90e0) resource busy 5, total 64
12:37:59 1077785792mS CMCallEvt: 0000000000000000 0.438181.0 -1 BaseEP: NEW CMEndpoint f17281f0 TOTAL NOW=14 CALL_LIST=6
12:37:59 1077785792mS CMCallEvt: 0000000000000000 0.438181.0 -1 PlaceMain.-1: NEW CMExtnEndpoint f17281f0, Name=PlaceMain, Extn=7100, Phys Extn=7100
12:37:59 1077785793mS CMTARGET: 0a640c150006afa5 0.438181.0 105596 PlaceMain.0: ADD PRIMARY
12:37:59 1077785794mS CMTARGET: FoundKnownSystemTargets ICR cache hit
12:37:59 1077785794mS CMTARGET: 0a640c150006afa2 17.438178.1 105596 SIPTrunk Endpoint: INITIAL TARGETING SUCCEEDED
12:37:59 1077785794mS CMTARGET: 0a640c150006afa2 17.438178.1 105596 SIPTrunk Endpoint: GetNoAnswerTimer:25
12:37:59 1077785794mS CMCallEvt: 0a640c150006afa2 17.438178.1 105596 SIPTrunk Endpoint: StateChange: END=A CMCSDialInitiated->CMCSDialled
12:37:59 1077785796mS CMCallEvt: 0000000000000000 0.438179.0 105596 TargetingEP: StateChange: END=B CMCSIdle->CMCSOffering
12:37:59 1077785797mS CMCallEvt: 0a640c150006afa5 0.438181.0 105596 PlaceMain.0: StateChange: END=T CMCSIdle->CMCSOffering
12:37:59 1077785798mS CMExtnEvt: PlaceMain: CMExtnHandler::SetCurrent( id: 0->438181 )
12:37:59 1077785798mS CMCallEvt: 0a640c150006afa5 0.438181.0 105596 PlaceMain.0: StateChange: END=T CMCSOffering->CMCSRinging
12:37:59 1077785798mS CMExtnEvt: v=18 State, new=Ringing old=Idle,0,0,PlaceMain
12:37:59 1077785799mS CMCallEvt: 0000000000000000 0.438179.0 105596 TargetingEP: StateChange: END=B CMCSOffering->CMCSRinging
12:37:59 1077785800mS CMCallEvt: 0a640c150006afa2 17.438178.1 105596 SIPTrunk Endpoint: StateChange: END=A CMCSDialled->CMCSRingBack
12:37:59 1077785801mS SIP Tx: UDP 192.168.XXX.30:5060 -> 12.194.XXX.5:5060
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 12.194.XXX.5:5060;branch=z9hG4bKqgq6301080ogof0jp5s0.1
From: "John Nameless" <sip:7XXX522939@12.194.XXX.5:5060>;tag=567948102643999_c2b06.1.2.1421996196436.0_31099878_61720834
Call-ID: 5509373937432032@12.114.58.38
CSeq: 2 INVITE
Contact: <sip:8XXXX87871@192.168.XXX.30:5060;transport=udp>
Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,INFO,NOTIFY
Supported: timer
Server: IP Office 9.1.3.0 build 120
To: <sip:8XXXX87871@192.168.XXX.30>;tag=40eebb191d735822
Content-Length: 0

 

[cdiris]

Here are the monitor files in .rtf format
not working:

https://www.dropbox.com/s/dua957r0buy9sk5/ATT SIP 404a trace.rtf?dl=0

working:

https://www.dropbox.com/s/ww5n18mhblgyu3p/ATT SIP working trace.rtf?dl=0

 

[amriddle01]

The working call shows the call hitting incoming group 0 which is the default group for Incoming call route entries, the one that fails is hitting incoming line group 7100.

I imagine you don't have any entries in ICR that will match that incoming line group

 

[cdiris]

@amriddle01
Thanks! Now the light is starting to turn on for me as to what that part of the trace meant. Now I have to figure out why the call would be hitting that group and not going through the 0 group which has all "*" The 7100 group is used for outbound CID only (with use internal data selected). I have the User SIP tabs set with the numbers. Not sure why some work and some don't but looks like I can fix it then by creating a route or just replacing 7100 with 0. So any ideas why it would try to force going through 7100 when there are wildcard entries for the 0 group? Maybe ATT is sending 4 digits instead of 10 and that is affecting it? I have this kind of setup all over the place without this issue (including the customers' current numbers which all work).

 

[amriddle01]

They are sending 4 digits:

Working - "called_party=8317587871"
Not Working - "called_party=5227"

 

[amriddle01]

Sorry, no they aren't, they are sending the full number in the setup, the system is narrowing it to 4 due to the line gp I guess

 

[cdiris]

Well it seems like strange behavior to me since the IPO should still match right to left and send the call through the wildcard entry but I'll make changes to allow calls through the other URI by changing 7100 to 0. Thanks again for the help.

 

[cdiris]

Just saw your third post. Sorry if I'm slow but what is the "line gp"? I'm very curious why the IPO would shorten the number for matching if that is what you are suggesting.

The only other discrepancy I see at the beginning of the invite is that the Caller ID doesn't have a valid IP address. Would that matter?

 

[amriddle01]

It should be a valid address indeed, ask them why they are sending nonsense in that field of their invite

 

[cdiris]

Will do

 

[cdiris]

line gp = line group
I was definitely overthinking that one

 

[cdiris]

If anyone has more info on if not having a public IP (or any IP address) in the Call ID field of the header would cause IP Office to not send a call through a default Route/URI please let me know. Or if you've encountered this problem due to something else. Maybe it is just something about 9.1.3 and the particular way ATT pretests their numbers? I haven't seen this same behavior on any of our other IP Office units on ATT SIP. Thanks much!

 

[cdiris]

In looking at traces for other customers I'm seeing a number of them where the Call ID is coded as something other than an IP Address. According to users on a Cisco site I was looking at, this is becoming more common and avoids any possibility that a router would translate the address in the field "accidentally" to a local address.

It's not looking like that is the cause of my problem with ATT on some incoming calls. I will probably need a more detailed trace to find out anything more. Today I'll be setting the 7100 group to 0 to allow any "stray" calls to come through the URI that is set to User Data and I'm expecting that to work.

 

[amriddle01]

Sending nonsense information in an IP address field just because some people can't turn SIP ALG off on their router is just plain stupid and sounds like bollocks to me, if it can be nonsense and still work why would it being an internal address make any difference? That's not even the address that gets changed by routers anyway in my experience, additionally addresses get re-written on outbound traffic not inbound....

 

[cdiris]

Well maybe it was just nonsense then or maybe I didn't summarize correctly. I definitely see your point about SIP ALG and that the ID should still remain consistent even if changed (and that it shouldn't be changing anyway). I think I found the post I was looking at that was at Stack Overflow and not Cisco. Can we post links on here? Just in case someone wants to find the comments, I searched Google for "Sip header Call ID" and it was the 4th entry titled "Call-ID and Branch tags in SIP protocol - Stack Overflow