SIP trunks not able to dial some numbers.

[PhoneDude20]

IP Office 11.1

We have a new issue dialing just a few numbers that just came up. Issue just came up and no changes have been made on the PBX or the firewall. When the call is attempted, on the pbx side we get waiting for line with the 3 beeps. However, the call does ring the remote end. We are able to call other numbers with the same area 212 code. Below are the monitor logs and carrier logs. Carrier is Broadvoice. The carrier is sending 200 ok and we are receiving 200 ok but we are not responding. Towards the bottom of the monitor logs. it has the following message [highlight #FCE94F]Retarget existing BUSY targets - Num of Busy Targets: 1 - Current Form: Broadvoice[/highlight] What does that mean?

10:23:54 119739591mS SIP Tx: UDP 192.168.1.250:5060 -> 206.15.174.61:5060
INVITE sip:2124569616@206.15.174.61 SIP/2.0
Via: SIP/2.0/UDP 12.12.12.12:5060;rport;branch=z9hG4bK6acd0e2e5297fc37ee4ecd1c847be571
From: "Bob Smith" <sip:2124547890@206.15.174.61>;tag=104f0355b3eb4dfc
To: <sip:2124569616@206.15.174.61>
Call-ID: 2ca762f9f290a8c288bfb15c5a42e235
CSeq: 1482142090 INVITE
Contact: "Bob Smith" <sip:2124547890@12.12.12.12:5060;transport=udp>
Max-Forwards: 70
Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,INFO,NOTIFY,UPDATE
Supported: timer
User-Agent: IP Office 11.1.2.3.0 build 47
P-Asserted-Identity: "2124547890" <sip:2124547890@12.12.12.12:5060>
Content-Type: application/sdp
Content-Length: 304

v=0
o=UserA 3965456028 298506257 IN IP4 12.12.12.12
s=Session SDP
c=IN IP4 12.12.12.12
t=0 0
m=audio 49152 RTP/AVP 0 8 18 4 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:4 G723/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

CMReleaseComp
Line: type=SIPLine 18 Call: lid=18 id=1946158707 in=0
Called[] Type=Default (100) Reason=CMDRdirect Calling[@sippbx.broadvoice.com] Type=Default Plan=Unknown
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=92124569616
IE CMIEDeviceDetail (231) 0a01011f74000673 LOCALE=enu HW=15 VER=11 class=CMDeviceSIPTrunk type=0 number=18 channel=1 features=0x1 rx_gain=32 tx_gain=32
ep_callid=1946158707 ipaddr=192.168.1.250 apps=0 loc=999 em_a_loc=999 em_d_loc=0 features2=0x0 is_spcall=1 ignores_dtmf=0
avgsid=<>
Cause=38, Network out of order
10:23:56 119741191mS CMARS: LINE ep Received: CMReleaseComp - child->state = CMCSOffering - ARS Call State = CMCSOverlapRecv
10:23:56 119741192mS CMLineTx: v=0
CMReleaseComp
Line: type=SIPLine 18 Call: lid=18 id=1946158707 in=0
Cause=16, Normal call clearing
10:23:56 119741192mS CMCallEvt: 0a01011f74000673 18.1946158707.0 -1 SIPTrunk Endpoint: StateChange: END=X CMCSOffering->CMCSDelete
10:23:56 119741192mS CMARS: ModifyCMARSTarget: Short_Code: 212456XXXX - Line_Group_ID: 10 set line status to CMARS_OUTOFSERVICE
10:23:56 119741192mS CMARS: Target: Short_Code: 212456XXXX - Line_Group_ID: 10 has been set to: CMARS_OUTOFSERVICE
10:23:56 119741193mS CMCallEvt: 0a01011f74000670 0.1946158706.0 190 ARS for Broadvoice: StateChange: END=B CMCSOverlapRecv->CMCSAccept
10:23:56 119741193mS CMCallEvt: 0a01011f74000670 253.1946158704.0 190 Bob Smith.0: StateChange: END=A CMCSDialled->CMCSRingBack
10:23:56 119741195mS CMExtnTx: v=258, p1=0
CMFacility
Line: type=SIPLine 260 Call: lid=253 id=1946158704 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
IE CMIEDtmf (209) CMIEDtmf oob 1, txp 101, rxp 101, fmtp = <null>, misc 21 (misc oob 0 misc rfc2833 1 prio oob 1 prio rfc2833 0)
IE CMIESecurityData (253) 2 item(s)
CMSecurityElement RX_ONLY {
CMSRTPCryptoCapability none
Codecs list (size 4)
}
CMSecurityElement TX_ONLY {
CMSRTPCryptoCapability none
Codecs list (size 4)
}
Timed: 09/08/24 10:23
10:23:56 119741198mS SIP Tx: TCP 192.168.1.250:5060 -> 192.168.1.67:23224
INVITE sip:258@192.168.1.67:23224;transport=tcp SIP/2.0
v: SIP/2.0/TCP 192.168.1.250:5060;rport;branch=z9hG4bK75c9f030cab8c2f3a24f9f15c073eb0e
f: <sip:CCMSInterface@192.168.1.250>;tag=dc6566ba27e4236a
t: <sip:258@192.168.1.250>;tag=66b41c4d-8189c44n3m3d4n3f4p2v534s494873_F258
i: 1_66b41c4d55807dfe353e4oe5838q3e4a6a3x2x_I258
CSeq: 1082 INVITE
m: <sip:CCMSInterface@192.168.1.250:5060;transport=tcp>
Max-Forwards: 70
Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,INFO,REFER,NOTIFY,SUBSCRIBE,REGISTER,PUBLISH,UPDATE
User-Agent: IP Office 11.1.2.3.0 build 47
c: application/sdp
l: 142

v=0
o=UserA 1117635035 4239127664 IN IP4 192.168.1.250
s=Session SDP
c=IN IP4 192.168.1.250
t=0 0
m=audio 49154 RTP/AVP 0
a=rtpmap:0 PCMU/8000
10:23:56 119741199mS CMExtnEvt: v=0 State, new=Alerting old=Proceeding,0,0,Nate Anderson
10:23:56 119741202mS CMExtnTx: v=258, p1=0
CMProgress
Line: type=SIPLine 260 Call: lid=253 id=1946158704 in=0
IE CMIEProgressIndicator (30) cs=CMCSITUT (0), loc=CMLUser (0), pd=CMPDInbandPattern (8)
Display [WAITING_FOR_LINE]
Timed: 09/08/24 10:23
10:23:56 119741202mS NAT: EPNatMediaHelper f184c7fc destroyed, parent f196fee4 list size 1
10:23:56 119741203mS CMCallEvt: 0a01011f74000673 18.1946158707.0 -1 BaseEP: DELETE CMEndpoint f185fac0 TOTAL NOW=2 CALL_LIST=1
10:23:56 119741203mS CD: CALL: 253.1946158704.0 BState=Ringing Cut=3 Music=0.0 Aend="Nate Anderson(258)" (0.0) Bend="" [] (0.0) CalledNum=92124569616 () CallingNum=258 (Bob Smith) Internal=1 Time=3634 AState=Ringing
10:23:56 119741205mS H323Evt: SESS 108 SetOperational local 192.168.1.250:0 remote 0.0.0.0:0 to 0
10:23:56 119741205mS H323Evt: SESS 108 Configure: Ulaw64K packet size 160
10:23:56 119741205mS H323Evt: SESS 108 SetRemUDP 0 -> 49152, remote IP 0.0.0.0 -> 192.168.1.67
10:23:56 119741207mS CMMap: a=21.11 b=0.0 DTMF::AllocateRAS allocated CMRTVoicemail(f568a4d8) resource busy -47, total 45
10:23:56 119741207mS CMMap: a=21.11 b=1.65535 T
10:23:56 119741207mS CMMap: PCG::AddToneGenerator g T[196] for cp[685]b0r1 append pcp[687]b0r1 (total 1)
10:23:56 119741208mS CMMap: a=0.18 b=0.0 IP::ReserveCodec pcp[687]b0r1 allocated CMRTVocoder(f564aec0) resource busy 1, total 20, codec type 5
10:23:56 119741208mS CMMap: a=21.11 b=0.18 M22
10:23:56 119741208mS CMMap: PlatformConnectionAudioSAP::Bind pcp[687]b0r1 to 0.18
10:23:56 119741208mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[687]b0r1 Configure 0.18
10:23:56 119741208mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[687]b0r1 ConnectIndication 0.18
10:23:56 119741209mS CMMap: PCG::MapBChan pcp[685]b0r1 cp_b 0 other_cp_b 0 type CGTypeDTMF
10:23:56 119741209mS H323Evt: SESS 108 SetOperational local 192.168.1.250:49154 remote 192.168.1.67:49152 to 1
10:23:56 119741209mS CMMap: DTMF:layTones g T[196] Tones ',EEEEE'
10:23:56 119741209mS CMMap: Started playing tones, cp[685]b0r1 (from g null)
10:23:56 119741209mS CMMap: cp[685]b0r1 SetOperGroup2 from g null to g null not executed, playing tones in progress ,EEEEE
10:23:56 119741213mS SIP Rx: TCP 192.168.1.67:23224 -> 192.168.1.250:5060
SIP/2.0 100 Trying
From: <sip:CCMSInterface@192.168.1.250>;tag=dc6566ba27e4236a
To: <sip:258@192.168.1.250>;tag=66b41c4d-8189c44n3m3d4n3f4p2v534s494873_F258
Call-ID: 1_66b41c4d55807dfe353e4oe5838q3e4a6a3x2x_I258
CSeq: 1082 INVITE
Via: SIP/2.0/TCP 192.168.1.250:5060;branch=z9hG4bK75c9f030cab8c2f3a24f9f15c073eb0e
User-Agent: Avaya J179 IP Phone 4.0.7.0.7 c81feabb4d99
Content-Length: 0

10:23:56 119741362mS SIP Rx: TCP 192.168.1.67:23224 -> 192.168.1.250:5060
SIP/2.0 200 OK
From: <sip:CCMSInterface@192.168.1.250>;tag=dc6566ba27e4236a
To: <sip:258@192.168.1.250>;tag=66b41c4d-8189c44n3m3d4n3f4p2v534s494873_F258
Call-ID: 1_66b41c4d55807dfe353e4oe5838q3e4a6a3x2x_I258
CSeq: 1082 INVITE
Via: SIP/2.0/TCP 192.168.1.250:5060;branch=z9hG4bK75c9f030cab8c2f3a24f9f15c073eb0e
Supported: 100rel,eventlist,feature-ref,replaces,tdialog,vnd.avaya.stimulus-ipo
Allow: INVITE,ACK,BYE,CANCEL,SUBSCRIBE,NOTIFY,MESSAGE,REFER,INFO,PRACK,PUBLISH,UPDATE
User-Agent: Avaya J179 IP Phone 4.0.7.0.7 c81feabb4d99
Contact: <sip:258@192.168.1.67:23224;transport=tcp>
Content-Type: application/sdp
Content-Length: 207

v=0
o=sip:258@192.168.1.67 1 59 IN IP4 192.168.1.67
s=sip:258@192.168.1.67
c=IN IP4 192.168.1.67
b=TIAS:1920000
t=0 0
m=audio 49152 RTP/AVP 0
c=IN IP4 192.168.1.67
b=TIAS:64000
a=ptime:20
a=rtpmap:0 PCMU/8000/1
10:23:56 119741366mS SIP Tx: TCP 192.168.1.250:5060 -> 192.168.1.67:23224
ACK sip:258@192.168.1.67:23224;transport=tcp SIP/2.0
v: SIP/2.0/TCP 192.168.1.250:5060;rport;branch=z9hG4bKbf35d5420735ffd43a7c7b488071fbba
f: <sip:CCMSInterface@192.168.1.250>;tag=dc6566ba27e4236a
t: <sip:258@192.168.1.250>;tag=66b41c4d-8189c44n3m3d4n3f4p2v534s494873_F258
i: 1_66b41c4d55807dfe353e4oe5838q3e4a6a3x2x_I258
CSeq: 1082 ACK
Max-Forwards: 70
User-Agent: IP Office 11.1.2.3.0 build 47
l: 0

10:23:56 119741523mS RES: Fri 9/8/2024 10:23:56 FreeMem=55832992 Heap=55228296(3) Cache=604696 MemObjs=16800(Max 18915) CMMsg=6(8) ASN=0 Buff=5200 1363 1000 7444 5 Links=57630(58029) BTree=1390(1987) CB=6058 MCT=0 CPU=10.56% CPUStats=15.64%/13/29/591/16
592/20268/00.25%/1/02.49% MCR=0 MCW=0 DEV=0
10:23:56 119741524mS RES2: IP 500 V2 11.1.2.3.0 build 47 Tasks=56 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=12+123 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1 SSA=0 TCP=75(TLS=9 OFF=0) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
10:23:56 119741524mS RES4: XML MemObjs=8 PoolMem=4748404(2) FreeMem=4736284(0) HeapUsed=0
10:23:56 119741524mS RES5: CLog MemObjs=1758 FreePoolMem(Objs)=2352(42) TotalMem=100800 StringsTotalMem=199850
10:23:57 119742388mS H323Evt: SESS 108: RTP(50t): 192.168.1.250/49154 192.168.1.67/49152 CODEC=Ulaw64K(5) PKTSZ=160 RFC2833=off AGE=1183 SENT=50 (avg size=160) RECV=50 (avg size=160)
10:23:57 119742607mS H323Evt: Recv: RegistrationRequest 10.2.1.68; Extn(109), time since last RRQ-KA 55013, Endpoints registered: 49; Endpoints in registration: 0
10:23:57 119742891mS SIP Rx: UDP 206.15.174.61:5060 -> 192.168.1.250:5060
SIP/2.0 183 Session Progress
v:SIP/2.0/UDP 12.12.12.12:5060;received=12.12.12.12;rport=5060;branch=z9hG4bK6acd0e2e5297fc37ee4ecd1c847be571
Record-Route:<sip:206.15.174.51;r2=on;lr=on;nat=yes>,<sip:206.15.174.61;r2=on;lr=on;nat=yes>
f:"Bob Smith"<sip:2124547890@206.15.174.61>;tag=104f0355b3eb4dfc
t:<sip:2124569616@206.15.174.61>;tag=87QHycp46FcBc
i:2ca762f9f290a8c288bfb15c5a42e235
CSeq:1482142090 INVITE
m:<sip:2124569616@206.15.174.131:5080;transport=udp>
User-Agent:fs
Accept:application/sdp
Allow:INVITE,ACK,BYE,CANCEL,OPTIONS,MESSAGE,INFO,UPDATE,REGISTER,REFER,NOTIFY,PUBLISH,SUBSCRIBE
k:timer,path,replaces
u:talk,hold,conference,presence,as-feature-event,dialog,line-seize,call-info,sla,include-session-description,presence.winfo,message-summary,refer
c:application/sdp
Content-Disposition:session
l:208

v=0
o=fs 1723206392 1723206393 IN IP4 206.15.174.131
s=fs
c=IN IP4 206.15.174.131
t=0 0
m=audio 10790 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
10:23:57 119742906mS H323Evt: Recv: RegistrationRequest 10.2.1.69; Extn(209), time since last RRQ-KA 55003, Endpoints registered: 49; Endpoints in registration: 0
10:23:58 119743030mS CMMap: PCG::UnmapBChan pcp[685]b0r1 cp_b 0 other_cp_b 0
10:23:58 119743030mS H323Evt: SESS 108 SetOperational local 192.168.1.250:49154 remote 192.168.1.67:49152 to 0
10:23:58 119743030mS CMMap: PCG::UnmapBChan pcp[687]b0r1 cp_b f5695f98 other_cp_b f568a394
10:23:58 119743030mS CMMap: a=21.11 b=0.18 M02
10:23:58 119743030mS CMMap: a=21.11 b=0.0 T0
10:23:58 119743032mS CMMap: a=21.11 b=0.0 DTMF::~DTMF freed CMRTUnknown(f568a4d8) resource busy 1, total 45
10:23:58 119743033mS CMMap: a=0.18 b=0.0 IP::FreeCodec pcp[687]b0r1 freed CMRTVocoder(f564aec0) resource busy 1, total 20
10:23:58 119743895mS H323Evt: Recv: RegistrationRequest 10.2.1.74; Extn(115), time since last RRQ-KA 55003, Endpoints registered: 49; Endpoints in registration: 0
[highlight #FCE94F]10:23:59 119744192mS CMARS: Retarget existing BUSY targets - Num of Busy Targets: 1 - Current Form: Broadvoice[/highlight]
10:23:59 119744195mS CMMap: a=21.11 b=0.0 DTMF::AllocateRAS allocated CMRTVoicemail(f568a4d8) resource busy -47, total 45
10:23:59 119744195mS CMMap: a=21.11 b=1.65535 T
10:23:59 119744195mS CMMap: PCG::AddToneGenerator g T[197] for cp[685]b0r1 append pcp[688]b0r1 (total 1)
10:23:59 119744195mS CMMap: a=0.18 b=0.0 IP::ReserveCodec pcp[688]b0r1 allocated CMRTVocoder(f564aec0) resource busy 1, total 20, codec type 5
10:23:59 119744195mS CMMap: a=21.11 b=0.18 M22
10:23:59 119744195mS CMMap: PlatformConnectionAudioSAP::Bind pcp[688]b0r1 to 0.18
10:23:59 119744195mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[688]b0r1 Configure 0.18
10:23:59 119744196mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[688]b0r1 ConnectIndication 0.18
10:23:59 119744196mS CMMap: PCG::MapBChan pcp[685]b0r1 cp_b 0 other_cp_b 0 type CGTypeDTMF
10:23:59 119744196mS H323Evt: SESS 108 SetOperational local 192.168.1.250:49154 remote 192.168.1.67:49152 to 1
10:23:59 119744196mS CMMap: DTMF:layTones g T[197] Tones ',EEEEE'
10:23:59 119744197mS CMMap: Started playing tones, cp[685]b0r1 (from g null)
10:23:59 119744197mS CMMap: cp[685]b0r1 SetOperGroup2 from g null to g null not executed, playing tones in progress ,EEEEE
10:24:00 119745126mS H323Evt: Recv: RegistrationRequest 10.2.1.71; Extn(102), time since last RRQ-KA 55014, Endpoints registered: 49; Endpoints in registration: 0
10:24:01 119746018mS CMMap: PCG::UnmapBChan pcp[685]b0r1 cp_b 0 other_cp_b 0
10:24:01 119746018mS H323Evt: SESS 108 SetOperational local 192.168.1.250:49154 remote 192.168.1.67:49152 to 0
10:24:01 119746018mS CMMap: PCG::UnmapBChan pcp[688]b0r1 cp_b f5695f98 other_cp_b f568a394
10:24:01 119746018mS CMMap: a=21.11 b=0.18 M02
10:24:01 119746018mS CMMap: a=21.11 b=0.0 T0
10:24:01 119746021mS CMMap: a=21.11 b=0.0 DTMF::~DTMF freed CMRTUnknown(f568a4d8) resource busy 1, total 45
10:24:01 119746021mS CMMap: a=0.18 b=0.0 IP::FreeCodec pcp[688]b0r1 freed CMRTVocoder(f564aec0) resource busy 1, total 20

********** Warning: Logging to Screen Stopped **********


Below are the logs from the carrier Broadvoice.

 

[sizbut]

Cheers for nothing. You tell us what you can dial, but nothing about what you can't dial, and expect us to scroll through a really long trace to puzzle it out for you rather than you giving us a clue. Well, it's the weekend, so I'm off to do more relaxing things instead.

Stuck in a never ending cycle of file copying.

 

[PhoneDude20]

I am trying to call 212-456-9616 and that fails. I can dial other 212 area codes that use the same short code and ARS table.

 

[Nortel4Ever]

It's obviously your SIP provider...