Outbound call incompatible from single phone

[j.flanagan]

I have a customer with about 180 users, mostly digital phones, on r11.0.4... using a fiber supplied PRI for their service. The issue I'm having is this... the receptionist, and only the receptionist gets incompatible and the turkey tone on all of her outbound calls. The ARS short code is Ns954522xxxx (xxxxs being their last 4 of their main number). That works for all of their outbound calls except the receptionist. This wasn't an issue when they were on early R8. However, over the covid time we upgraded them to r11 and now that they are coming back to the office they have run into this issue.

The only strange thing is that the receptionists extension is the same 4 digits as the last 4 of the main number.

Heres a trace, let me know if anyone has ideas of what could be wrong or what we could try.

To me, it looks the call call is making it out to the PRI. I suppose that means its being denied by the carrier...

11:48:24 681502888mS CMCallEvt: 0000000000000000 0.25464.0 -1 TargetingEP: StateChange: END=X CMCSOffering->CMCSDelete
11:48:24 681502888mS CMCallEvt: 0000000000000000 0.25464.0 -1 BaseEP: DELETE CMEndpoint f5137acc TOTAL NOW=6 CALL_LIST=2
11:48:24 681502888mS CD: CALL: 0.25463.0 BState=Idle Cut=2 Music=0.0 Aend="Receptionist(5334)" (8.9) Bend="" [] (0.0) CalledNum=8 () CallingNum=5334 (Receptionist) Internal=1 Time=13 AState=Dialling
11:48:25 681503190mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,5334: Digit Key Pressed 7
11:48:25 681503191mS CMARS: FORM: BCPA - Received Number: 7
11:48:25 681503191mS CMARS: CMARSTargetingPending
11:48:25 681503354mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,5334: Digit Key Pressed 8
11:48:25 681503355mS CMARS: FORM: BCPA - Received Number: 78
11:48:25 681503355mS CMARS: CMARSTargetingPending
11:48:25 681503577mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,5334: Digit Key Pressed 6
11:48:25 681503578mS CMARS: FORM: BCPA - Received Number: 786
11:48:25 681503579mS CMARS: CMARSTargetingPending
11:48:25 681503790mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,5334: Digit Key Pressed 3
11:48:25 681503791mS CMARS: FORM: BCPA - Received Number: 7863
11:48:25 681503791mS CMARS: CMARSTargetingPending
11:48:25 681503971mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,5334: Digit Key Pressed 4
11:48:25 681503972mS CMARS: FORM: BCPA - Received Number: 78634
11:48:25 681503972mS CMARS: CMARSTargetingPending
11:48:26 681504403mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,5334: Digit Key Pressed 6
11:48:26 681504404mS CMARS: FORM: BCPA - Received Number: 786346
11:48:26 681504404mS CMARS: CMARSTargetingPending
11:48:26 681504605mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,5334: Digit Key Pressed 5
11:48:26 681504606mS CMARS: FORM: BCPA - Received Number: 7863465
11:48:26 681504606mS CMARS: CMARSTargetingPending
11:48:26 681504822mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,5334: Digit Key Pressed 6
11:48:26 681504823mS CMARS: FORM: BCPA - Received Number: 78634656
11:48:26 681504823mS CMARS: CMARSTargetingPending
11:48:26 681504944mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,5334: Digit Key Pressed 6
11:48:26 681504945mS CMARS: FORM: BCPA - Received Number: 786346566
11:48:26 681504945mS CMARS: CMARSTargetingPending
11:48:27 681505217mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,5334: Digit Key Pressed 0
11:48:27 681505218mS CMARS: FORM: BCPA - Received Number: 7863465660
11:48:27 681505218mS CMARS: CMARSTargetingPending
11:48:27 681505804mS ISDNL3Evt: v=1 p1=1,p2=1001,p3=5,p4=0,s1=
11:48:28 681506041mS ISDNL3Evt: v=13 p1=13,p2=1001,p3=5,p4=0,s1=

********** SysMonitor v11.0.0.1.0 build 8 [connected to 192.168.150.80 (BCPA)] **********
11:48:30 681509884mS CMARS: Case 1 - dial_delay_time: 4000 has expired - Resolve what we might have - Called Number: 7863465660 Addr: f1826cf0
11:48:30 681509884mS CMARS: FORM: BCPA - Received Number: 7863465660
11:48:30 681509884mS CMARS: FOUND A SHORT CODE - short_code: XXXXXXXXXXN; - Tel: N - Called_Party: 7863465660 - Line Group Id: 1
11:48:30 681509884mS CMARS: SetCurrentTarget: Short_Code: XXXXXXXXXXN; - Line_Group_ID: 1
11:48:30 681509885mS CMARS: FindActiveARSByGroupID GroupID=1 - Not Found
11:48:30 681509885mS CMLRQ: FindActiveLRQByGroupID GroupID=1 - Not Found
11:48:30 681509885mS CMTARGET: Group Id: 1 has NOT been found in Line: 1
11:48:30 681509885mS CMTARGET: Group Id: 1 has NOT been found in Line: 13
11:48:30 681509885mS CMCallEvt: 0000000000000000 0.25466.0 -1 BaseEP: NEW CMEndpoint f187c528 TOTAL NOW=7 CALL_LIST=2
11:48:30 681509886mS CMTARGET: ISDN BChannel 22: in-service check = 1
11:48:30 681509887mS CMARS: ModifyCMARSTarget: Short_Code: XXXXXXXXXXN; - Line_Group_ID: 1 set line status to CMARS_TRYING
11:48:30 681509887mS CMARS: FOUND LINE - Line Id: 2 - using line group id: 1 (code XXXXXXXXXXN;, line 1) - Called Number: 7863465660 - Calling Number: 5334
11:48:30 681509887mS CMARS: SEND Setup TO LINE
11:48:30 681509888mS CMCallEvt: c0a896500000637a 0.25466.0 7015 Q931 Trunk:2 CHAN=22: StateChange: END=child CMCSIdle->CMCSOffering
11:48:30 681509889mS CMLineTx: v=2
CMSetup
Line: type=Q931Line 2 Call: lid=0 id=25466 in=0
Called[7863465660] Type=National (2) Reason=CMDRdirect Calling[] Type=National Plan=ISDN
BC: CMTC=3K1Audio CMTM=CallIndSigCon CMTR=64 CMST=Default CMU1=ULaw
BChan: slot=0 chan=22
Locale: enu
11:48:30 681509889mS CD: CALL: 0.25463.0 BState=Idle Cut=2 Music=0.0 Aend="Receptionist(5334)" (8.9) Bend="" [Line 2] (0.0) CalledNum=87863465660 () CallingNum=5334 (Receptionist) Internal=1 Time=7014 AState=Dialling
11:48:30 681509893mS ISDNL3Evt: v=2 stacknum=2 State, new=Initiated, old=NullState id=25466
11:48:30 681509903mS ISDNL3Evt: v=2 stacknum=2 State, new=Proceeding, old=Initiated id=25466
11:48:30 681509904mS CMLineRx: v=2
CMProceeding
Line: type=Q931Line 2 Call: lid=0 id=25466 in=0
BChan: slot=0 chan=22
11:48:30 681509904mS CMARS: LINE ep Received: CMProceeding - child->state = CMCSOffering - ARS Call State = CMCSOverlapRecv
11:48:30 681509904mS CMARS: LINE IS NOW THE B END OF THE CALL - CMARSEndpoint::RequestEnd()
11:48:30 681509905mS CMARS: CMARSEndpoint::CallLost(cause=124) - Address: c0a8965000006377 0.25465.0 7015 ARS for BCPA - Call State: CMCSOverlapRecv
11:48:30 681509905mS CMCallEvt: c0a8965000006377 0.25465.0 -1 ARS for BCPA: StateChange: END=X CMCSOverlapRecv->CMCSDelete
11:48:30 681509906mS CMCallEvt: c0a896500000637a 0.25466.0 7015 Q931 Trunk:2 CHAN=22: StateChange: END=B CMCSOffering->CMCSAccept
11:48:30 681509906mS CMCallEvt: c0a8965000006377 0.25463.0 7015 Receptionist.0: StateChange: END=A CMCSDialling->CMCSDialled
11:48:30 681509906mS CMExtnEvt: v=7 State, new=Proceeding old=Dialling,0,0,Receptionist
11:48:30 681509907mS CMCallEvt: c0a8965000006377 0.25465.0 -1 BaseEP: DELETE CMEndpoint f1826cf0 TOTAL NOW=6 CALL_LIST=2
11:48:30 681509908mS CD: CALL: 0.25463.0 BState=Ringing Cut=3 Music=0.0 Aend="Receptionist(5334)" (8.9) Bend="Line 2" [Line 2] (1.55) CalledNum=7863465660 () CallingNum=5334 (Receptionist) Internal=0 Time=7033 AState=Dialled
11:48:30 681509911mS ISDNL3Evt: v=2 stacknum=2 State, new=ReleaseReq, old=Proceeding id=25466
11:48:30 681509917mS ISDNL3Evt: v=2 stacknum=2 State, new=NullState, old=ReleaseReq id=25466
11:48:30 681509918mS CMLineRx: v=2
CMReleaseComp
Line: type=Q931Line 2 Call: lid=0 id=25466 in=0
BChan: slot=0 chan=22
Cause=1, Unallocated (unassigned) number
11:48:30 681509918mS CMCallEvt: c0a896500000637a 0.25466.0 7015 Q931 Trunk:2 CHAN=22: StateChange: END=B CMCSAccept->CMCSCompleted
11:48:30 681509920mS CMLOGGING: CALL:2022/02/1111:48,00:00:00,000,5334,O,7863465660,87863465660,Receptionist,,,0,,"",0,n/a
11:48:30 681509920mS CD: CALL: 0.25463.0 BState=Disconnecting Cut=1 Music=0.0 Aend="Receptionist(5334)" (8.9) Bend="Line 2" [Line 2] (1.55) CalledNum=7863465660 () CallingNum=5334 (Receptionist) Internal=0 Time=7045 AState=Dialled
11:48:30 681509922mS CD: CALL: 0.25463.0 Deleted
11:48:30 681509923mS CMExtnEvt: Receptionist: CALL LOST (CMCauseUnallocatedNumber)
11:48:30 681509924mS CMExtnEvt: Receptionist: Extn(5334) Calling Party Number(5334) Type(CMNTypeInternal)
11:48:30 681509925mS CMCallEvt: c0a8965000006377 0.25463.0 -1 Receptionist.0: StateChange: END=X CMCSDialled->CMCSCompletedTone
11:48:30 681509925mS CMExtnEvt: v=7 State, new=CMESCompleted old=Proceeding,0,0,Receptionist
11:48:30 681509926mS CMCallEvt: c0a896500000637a 0.25466.0 -1 Q931 Trunk:2 CHAN=22: StateChange: END=X CMCSCompleted->CMCSDelete
11:48:30 681509926mS CMCallEvt: END CALL:7015 (f1879534)
11:48:30 681509927mS CMTARGET: ISDN BChannel 22: in-service check = 1
11:48:30 681509928mS CMCallEvt: c0a896500000637a 0.25466.0 -1 BaseEP: DELETE CMEndpoint f187c528 TOTAL NOW=5 CALL_LIST=1

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

 

[TouchToneTommy]

11:48:30 681509887mS CMARS: FOUND LINE - Line Id: 2 - using line group id: 1 (code XXXXXXXXXXN;, line 1) - Called Number: 7863465660 - Calling Number: 5334

You're only sending 4 digits as the outgoing caller ID

 

[j.flanagan]

Here's a trace from a successful call.


12:46:07 1030571892mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,3318: Digit Key Pressed 2
12:46:07 1030571893mS CMARS: FORM: BCPA - Received Number: 2
12:46:07 1030571894mS CMARS: CMARSTargetingPending
12:46:08 1030572163mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,3318: Digit Key Pressed 1
12:46:08 1030572164mS CMARS: FORM: BCPA - Received Number: 21
12:46:08 1030572164mS CMARS: CMARSTargetingPending

********** SysMonitor v11.0.0.1.0 build 8 [connected to 192.168.150.80 (BCPA)] **********
12:46:08 1030572456mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,3318: Digit Key Pressed 2
12:46:08 1030572457mS CMARS: FORM: BCPA - Received Number: 212
12:46:08 1030572458mS CMARS: CMARSTargetingPending
12:46:10 1030574068mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,3318: Digit Key Pressed 8
12:46:10 1030574069mS CMARS: FORM: BCPA - Received Number: 2128
12:46:10 1030574069mS CMARS: CMARSTargetingPending
12:46:10 1030574284mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,3318: Digit Key Pressed 0
12:46:10 1030574285mS CMARS: FORM: BCPA - Received Number: 21280
12:46:10 1030574285mS CMARS: CMARSTargetingPending
12:46:11 1030575516mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,3318: Digit Key Pressed 4
12:46:11 1030575518mS CMARS: FORM: BCPA - Received Number: 212804
12:46:11 1030575518mS CMARS: CMARSTargetingPending

12:46:13 1030577918mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,3318: Digit Key Pressed 8
12:46:13 1030577919mS CMARS: FORM: BCPA - Received Number: 2128048
12:46:13 1030577920mS CMARS: CMARSTargetingPending
12:46:13 1030578367mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,3318: Digit Key Pressed 7
12:46:13 1030578368mS CMARS: FORM: BCPA - Received Number: 21280487
12:46:13 1030578369mS CMARS: CMARSTargetingPending
12:46:14 1030579040mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,3318: Digit Key Pressed 1
12:46:14 1030579041mS CMARS: FORM: BCPA - Received Number: 212804871
12:46:14 1030579042mS CMARS: CMARSTargetingPending
12:46:14 1030579271mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,3318: Digit Key Pressed 1
12:46:14 1030579272mS CMARS: FORM: BCPA - Received Number: 2128048711
12:46:14 1030579272mS CMARS: CMARSTargetingPending

********** SysMonitor v11.0.0.1.0 build 8 [connected to 192.168.150.80 (BCPA)] **********
12:46:20 1030584216mS CMARS: Case 1 - dial_delay_time: 4000 has expired - Resolve what we might have - Called Number: 2128048711 Addr: f180af2c
12:46:20 1030584216mS CMARS: FORM: BCPA - Received Number: 2128048711
12:46:20 1030584216mS CMARS: FOUND A SHORT CODE - short_code: XXXXXXXXXXN; - Tel: N - Called_Party: 2128048711 - Line Group Id: 1
12:46:20 1030584217mS CMARS: SetCurrentTarget: Short_Code: XXXXXXXXXXN; - Line_Group_ID: 1
12:46:20 1030584217mS CMARS: FindActiveARSByGroupID GroupID=1 - Not Found
12:46:20 1030584217mS CMLRQ: FindActiveLRQByGroupID GroupID=1 - Not Found
12:46:20 1030584217mS CMTARGET: Group Id: 1 has NOT been found in Line: 1
12:46:20 1030584217mS CMTARGET: Group Id: 1 has NOT been found in Line: 13
12:46:20 1030584217mS CMCallEvt: 0000000000000000 0.37581.0 -1 BaseEP: NEW CMEndpoint f1891d90 TOTAL NOW=15 CALL_LIST=6
12:46:20 1030584218mS CMTARGET: ISDN BChannel 22: in-service check = 1
12:46:20 1030584219mS CMARS: ModifyCMARSTarget: Short_Code: XXXXXXXXXXN; - Line_Group_ID: 1 set line status to CMARS_TRYING
12:46:20 1030584220mS CMARS: FOUND LINE - Line Id: 2 - using line group id: 1 (code XXXXXXXXXXN;, line 1) - Called Number: 2128048711 - Calling Number: 3318
12:46:20 1030584220mS CMARS: SEND Setup TO LINE

 

[j.flanagan]

Based on a foggy memory from when we ported them onto this PRI, I believe the carrier is only expecting to receive 4 digits. The trace I just posted with a successful call sending only 4 digits confirms that to me. Either way, it seems as if the system is sending the call to the carrier. What are some reasons the carrier might deny the call?

 

[critchey]

There is no real way for us to know the reason the carrier is rejecting the call based on the available information. You need to enable the PRI filters (just enable everything under ISDN tab). You should get some kind of response or error code from the provider on failed calls.

The truth is just an excuse for lack of imagination.

 

[Ekster]

From the traces, the unsuccessful call has caller ID of 5334 and the successful one 3318.

Is 5334 within your DDI range? If it isn't then that will be why the call is rejected.

“Some humans would do anything to see if it was possible to do it.
If you put a large switch in some cave somewhere, with a sign on it saying 'End-of-the-World Switch. PLEASE DO NOT TOUCH'.
The paint wouldn't even have time to dry.”

Terry Pratchet