PRI Issues on IP Office 1

dseevers · Jul 24, 2020

We have an issue with a customer location. Here is the setup. They have two trunk groups one with 4 analog lines for backup(dial 9) and they have a PRI (dial 8). There is probably 35 digital phones and about 200 analog phones for residents. The analog phones can dial out on 8 no problem. But we are unable to dial out on the PRI with any of the digital phones. This leads me to believe we have a DTMF issue between us and the service provider but they say they can't do anything because it is working for the residents so they are working fine. I captured a failed call and not sure how to take it. Any help would be appreciated.

10:34:23 2507842965mS PRN: Monitor Status IP 500 V2 9.1.6.0 build 153
10:34:23 2507842965mS PRN: LAW=U PRI=1, BRI=0, ALOG=4, VCOMP=10, MDM=0, WAN=0, MODU=5 LANM=0 CkSRC=5 VMAIL=1(VER=2 TYP=3) 1-X=0 CALLS=3(TOT=16797)
10:34:24 2507844097mS CMCallEvt: 0000000000000000 0.93680.0 -1 BaseEP: NEW CMEndpoint f17f35e0 TOTAL NOW=9 CALL_LIST=3
10:34:24 2507844097mS CMCallEvt: 0000000000000000 0.93680.0 -1 Extn246.-1: NEW CMExtnEndpoint f17f35e0, Name=Extn246, Extn=246, Phys Extn=246
10:34:24 2507844097mS CMCallEvt: CREATE CALL:16798 (f4cf4d70)
10:34:24 2507844097mS CMCallEvt: 0000000000000000 0.93681.0 -1 BaseEP: NEW CMEndpoint f4f703d8 TOTAL NOW=10 CALL_LIST=3
10:34:24 2507844099mS CMExtnEvt: Extn246: CMExtnHandler::SetCurrent( id: 0->93680 )
10:34:24 2507844099mS CMExtnRx: v=246, p1=0
CMSetup
Line: type=DigitalExtn 6 Call: lid=0 id=93680 in=0
Called[] Type=Default (100) Reason=CMDRdirect Calling[246] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=CallIndSigCon CMTR=64 CMST=Default CMU1=ULaw
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=Extn246
IE CMIECallingPartyKName (226)(Type=CMNameDefault) name=TC 400
10:34:24 2507844099mS CMCallEvt: c0a801fc00016df0 0.93680.0 16798 Extn246.0: StateChange: END=A CMCSIdle->CMCSDialInitiated
10:34:24 2507844100mS CMExtnEvt: v=30 State, new=Dialling old=Idle,0,0,Extn246
10:34:24 2507844100mS CMTARGET: c0a801fc00016df0 0.93680.0 16798 Extn246.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party= sub= calling=246 calling_sub= dir=out complete=0 ses=0
10:34:24 2507844100mS CMTARGET: c0a801fc00016df0 0.93680.0 16798 Extn246.0: ADD TARGET (N): number= type=100 depth=1 nobar=1 setorig=1 ses=0
10:34:24 2507844101mS CMCallEvt: c0a801fc00016df0 0.93680.0 16798 Extn246.0: StateChange: END=A CMCSDialInitiated->CMCSDialling
10:34:24 2507844101mS CMExtnTx: v=246, p1=0
CMSetupAck
Line: type=DigitalExtn 6 Call: lid=0 id=93680 in=0
BChan: slot=8 chan=32
Timed: 24/07/20 10:34
10:34:24 2507844103mS CD: CALL: 0.93680.0 BState=Idle Cut=1 Music=3.0 Aend="Extn246(246)" (8.32) Bend="" [] (0.0) CalledNum= () CallingNum=246 (Extn246) Internal=1 Time=6 AState=DialInitiated
10:34:24 2507844104mS CMMap: a=8.32 b=0.0 D1
10:34:24 2507844107mS RES: Fri 24/7/2020 10:34:25 FreeMem=52490620 Heap=51768932(2) Cache=721688 MemObjs=18282(18733) CMMsg=6(7) ASN=0 Buff=5200 1341 999 7404 5 Links=69927(70139) BTree=2042(4750) CPU=04.70% CPUStats=04.95%/1/5/811/12908/14472/00.09%/0/0
2.74% MCR=0 MCW=0
10:34:24 2507844107mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=51 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=79 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1 SSA=1 TCP=20(TLS=5) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
10:34:24 2507844107mS RES4: XML MemObjs=63 PoolMem=4748404(2) FreePoolMem=4733100(0)
10:34:24 2507844107mS RES5: CLog MemObjs=4563 FreePoolMem(Objs)=1924(37) TotalMem=613700
10:34:25 2507845977mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,246: Digit Key Pressed 8
10:34:25 2507845977mS CMExtnRx: v=246, p1=0
CMInformation
Line: type=DigitalExtn 6 Call: lid=0 id=93680 in=0
Called[8] Type=Default (100) Reason=CMDRdirect Keypad[8]
10:34:25 2507845977mS CMTARGET: c0a801fc00016df0 0.93680.0 16798 Extn246.0: Setting Hard Timer 4000
10:34:25 2507845978mS CMTARGET: c0a801fc00016df0 0.93680.0 16798 Extn246.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=8 sub= calling=246 calling_sub= dir=out complete=0 ses=0
10:34:25 2507845978mS CMTARGET: c0a801fc00016df0 0.93680.0 16798 Extn246.0: ADD TARGET (N): number=8 type=100 depth=1 nobar=1 setorig=1 ses=0
10:34:25 2507845980mS CMMap: a=8.32 b=0.0 D0
10:34:26 2507846966mS PRN: Optimizing BTree Lists Completed...Started:2507846965 Duration:1 Size:194 Attempted:194
10:34:27 2507847565mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,246: Digit Key Pressed 1
10:34:27 2507847566mS CMExtnRx: v=246, p1=0
CMInformation
Line: type=DigitalExtn 6 Call: lid=0 id=93680 in=0
Called[1] Type=Default (100) Reason=CMDRdirect Keypad[1]
10:34:27 2507847566mS CMTARGET: c0a801fc00016df0 0.93680.0 16798 Extn246.0: Setting Hard Timer 4000
10:34:27 2507847566mS CMTARGET: c0a801fc00016df0 0.93680.0 16798 Extn246.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=81 sub= calling=246 calling_sub= dir=out complete=0 ses=0
10:34:27 2507847566mS CMTARGET: c0a801fc00016df0 0.93680.0 16798 Extn246.0: ADD TARGET (N): number=81 type=100 depth=1 nobar=1 setorig=1 ses=0
10:34:28 2507848002mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,246: Digit Key Pressed 3
10:34:28 2507848003mS CMExtnRx: v=246, p1=0
CMInformation
Line: type=DigitalExtn 6 Call: lid=0 id=93680 in=0
Called[3] Type=Default (100) Reason=CMDRdirect Keypad[3]
10:34:28 2507848003mS CMTARGET: c0a801fc00016df0 0.93680.0 16798 Extn246.0: Setting Hard Timer 4000
10:34:28 2507848004mS CMTARGET: c0a801fc00016df0 0.93680.0 16798 Extn246.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=813 sub= calling=246 calling_sub= dir=out complete=0 ses=0
10:34:28 2507848004mS CMTARGET: c0a801fc00016df0 0.93680.0 16798 Extn246.0: ADD TARGET (N): number=813 type=100 depth=1 nobar=1 setorig=1 ses=0
10:34:28 2507848674mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,246: Digit Key Pressed 0
10:34:28 2507848674mS CMExtnRx: v=246, p1=0
CMInformation
Line: type=DigitalExtn 6 Call: lid=0 id=93680 in=0
Called[0] Type=Default (100) Reason=CMDRdirect Keypad[0]
10:34:28 2507848675mS CMTARGET: c0a801fc00016df0 0.93680.0 16798 Extn246.0: Setting Hard Timer 4000
10:34:28 2507848675mS CMTARGET: c0a801fc00016df0 0.93680.0 16798 Extn246.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=8130 sub= calling=246 calling_sub= dir=out complete=0 ses=0
10:34:28 2507848675mS CMTARGET: c0a801fc00016df0 0.93680.0 16798 Extn246.0: ADD TARGET (N): number=8130 type=100 depth=1 nobar=1 setorig=1 ses=0
10:34:28 2507848970mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,246: Digit Key Pressed 8
10:34:28 2507848970mS CMExtnRx: v=246, p1=0
CMInformation
Line: type=DigitalExtn 6 Call: lid=0 id=93680 in=0
Called[8] Type=Default (100) Reason=CMDRdirect Keypad[8]
10:34:28 2507848971mS CMTARGET: c0a801fc00016df0 0.93680.0 16798 Extn246.0: Setting Hard Timer 4000
10:34:28 2507848971mS CMTARGET: c0a801fc00016df0 0.93680.0 16798 Extn246.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=81308 sub= calling=246 calling_sub= dir=out complete=0 ses=0
10:34:28 2507848971mS CMTARGET: c0a801fc00016df0 0.93680.0 16798 Extn246.0: ADD TARGET (N): number=81308 type=100 depth=1 nobar=1 setorig=1 ses=0
10:34:29 2507849112mS RES: Fri 24/7/2020 10:34:30 FreeMem=52490628 Heap=51768932(2) Cache=721696 MemObjs=18282(18733) CMMsg=6(7) ASN=0 Buff=5200 1342 1000 7404 5 Links=69928(70139) BTree=2037(4750) CPU=05.00% CPUStats=04.55%/2/7/811/12910/14472/00.10%/0/
02.75% MCR=0 MCW=0
10:34:29 2507849112mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=51 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=75 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1 SSA=1 TCP=20(TLS=5) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
10:34:29 2507849112mS RES4: XML MemObjs=63 PoolMem=4748404(2) FreePoolMem=4733100(0)
10:34:29 2507849113mS RES5: CLog MemObjs=4563 FreePoolMem(Objs)=1924(37) TotalMem=613700
10:34:29 2507849881mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,246: Digit Key Pressed 6
10:34:29 2507849881mS CMExtnRx: v=246, p1=0
CMInformation
Line: type=DigitalExtn 6 Call: lid=0 id=93680 in=0
Called[6] Type=Default (100) Reason=CMDRdirect Keypad[6]
10:34:29 2507849882mS CMTARGET: c0a801fc00016df0 0.93680.0 16798 Extn246.0: Setting Hard Timer 4000
10:34:29 2507849882mS CMTARGET: c0a801fc00016df0 0.93680.0 16798 Extn246.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=813086 sub= calling=246 calling_sub= dir=out complete=0 ses=0
10:34:29 2507849882mS CMTARGET: c0a801fc00016df0 0.93680.0 16798 Extn246.0: ADD TARGET (N): number=813086 type=100 depth=1 nobar=1 setorig=1 ses=0
10:34:30 2507850176mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,246: Digit Key Pressed 2
10:34:30 2507850176mS CMExtnRx: v=246, p1=0
CMInformation
Line: type=DigitalExtn 6 Call: lid=0 id=93680 in=0
Called[2] Type=Default (100) Reason=CMDRdirect Keypad[2]
10:34:30 2507850177mS CMTARGET: c0a801fc00016df0 0.93680.0 16798 Extn246.0: Setting Hard Timer 4000
10:34:30 2507850177mS CMTARGET: c0a801fc00016df0 0.93680.0 16798 Extn246.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=8130862 sub= calling=246 calling_sub= dir=out complete=0 ses=0
10:34:30 2507850177mS CMTARGET: c0a801fc00016df0 0.93680.0 16798 Extn246.0: ADD TARGET (N): number=8130862 type=100 depth=1 nobar=1 setorig=1 ses=0
10:34:30 2507850455mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,246: Digit Key Pressed 7
10:34:30 2507850455mS CMExtnRx: v=246, p1=0
CMInformation
Line: type=DigitalExtn 6 Call: lid=0 id=93680 in=0
Called[7] Type=Default (100) Reason=CMDRdirect Keypad[7]
10:34:30 2507850456mS CMTARGET: c0a801fc00016df0 0.93680.0 16798 Extn246.0: Setting Hard Timer 4000
10:34:30 2507850456mS CMTARGET: c0a801fc00016df0 0.93680.0 16798 Extn246.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=81308627 sub= calling=246 calling_sub= dir=out complete=0 ses=0
10:34:30 2507850456mS CMTARGET: c0a801fc00016df0 0.93680.0 16798 Extn246.0: ADD TARGET (N): number=81308627 type=100 depth=1 nobar=1 setorig=1 ses=0
10:34:30 2507850814mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,246: Digit Key Pressed 2
10:34:30 2507850815mS CMExtnRx: v=246, p1=0
CMInformation
Line: type=DigitalExtn 6 Call: lid=0 id=93680 in=0
Called[2] Type=Default (100) Reason=CMDRdirect Keypad[2]
10:34:30 2507850815mS CMTARGET: c0a801fc00016df0 0.93680.0 16798 Extn246.0: Setting Hard Timer 4000
10:34:30 2507850815mS CMTARGET: c0a801fc00016df0 0.93680.0 16798 Extn246.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=813086272 sub= calling=246 calling_sub= dir=out complete=0 ses=0
10:34:30 2507850816mS CMTARGET: c0a801fc00016df0 0.93680.0 16798 Extn246.0: ADD TARGET (N): number=813086272 type=100 depth=1 nobar=1 setorig=1 ses=0
10:34:31 2507851078mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,246: Digit Key Pressed 6
10:34:31 2507851079mS CMExtnRx: v=246, p1=0
CMInformation
Line: type=DigitalExtn 6 Call: lid=0 id=93680 in=0
Called[6] Type=Default (100) Reason=CMDRdirect Keypad[6]
10:34:31 2507851079mS CMTARGET: c0a801fc00016df0 0.93680.0 16798 Extn246.0: Setting Hard Timer 4000
10:34:31 2507851079mS CMTARGET: c0a801fc00016df0 0.93680.0 16798 Extn246.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=8130862726 sub= calling=246 calling_sub= dir=out complete=0 ses=0
10:34:31 2507851080mS CMTARGET: c0a801fc00016df0 0.93680.0 16798 Extn246.0: ADD TARGET (N): number=8130862726 type=100 depth=1 nobar=1 setorig=1 ses=0
10:34:31 2507851392mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,246: Digit Key Pressed 7
10:34:31 2507851392mS CMExtnRx: v=246, p1=0
CMInformation
Line: type=DigitalExtn 6 Call: lid=0 id=93680 in=0
Called[7] Type=Default (100) Reason=CMDRdirect Keypad[7]
10:34:31 2507851393mS CMTARGET: c0a801fc00016df0 0.93680.0 16798 Extn246.0: Setting Hard Timer 4000
10:34:31 2507851393mS CMTARGET: c0a801fc00016df0 0.93680.0 16798 Extn246.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=81308627267 sub= calling=246 calling_sub= dir=out complete=0 ses=0
10:34:31 2507851393mS CMTARGET: c0a801fc00016df0 0.93680.0 16798 Extn246.0: ADD TARGET (N): number=81308627267 type=100 depth=1 nobar=1 setorig=1 ses=0
10:34:31 2507851657mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,246: Digit Key Pressed 1
10:34:31 2507851657mS CMExtnRx: v=246, p1=0
CMInformation
Line: type=DigitalExtn 6 Call: lid=0 id=93680 in=0
Called[1] Type=Default (100) Reason=CMDRdirect Keypad[1]
10:34:31 2507851658mS CMTARGET: c0a801fc00016df0 0.93680.0 16798 Extn246.0: Setting Hard Timer 4000
10:34:31 2507851658mS CMTARGET: c0a801fc00016df0 0.93680.0 16798 Extn246.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=813086272671 sub= calling=246 calling_sub= dir=out complete=0 ses=0
10:34:31 2507851658mS CMTARGET: c0a801fc00016df0 0.93680.0 16798 Extn246.0: ADD TARGET (N): number=813086272671 type=100 depth=1 nobar=1 setorig=1 ses=0

********** SysMonitor v11.0.4.2.0 build 58 [connected to 192.168.43.1 (Bethany Home)] **********
10:34:34 2507854970mS PRN: Monitor Status IP 500 V2 9.1.6.0 build 153
10:34:34 2507854971mS PRN: LAW=U PRI=1, BRI=0, ALOG=4, VCOMP=10, MDM=0, WAN=0, MODU=5 LANM=0 CkSRC=5 VMAIL=1(VER=2 TYP=3) 1-X=0 CALLS=4(TOT=16798)
10:34:35 2507855658mS CMTARGET: c0a801fc00016df0 0.93680.0 16798 Extn246.0: TimerExpired cause=CMTCDelayedProcessing
10:34:35 2507855658mS CMTARGET: c0a801fc00016df0 0.93680.0 16798 Extn246.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=813086272671 sub= calling=246 calling_sub= dir=out complete=1 ses=0
10:34:35 2507855658mS CMTARGET: c0a801fc00016df0 0.93680.0 16798 Extn246.0: ADD TARGET (N): number=813086272671 type=100 depth=1 nobar=1 setorig=1 ses=0
10:34:35 2507855659mS CMTARGET: c0a801fc00016df0 0.93680.0 16798 Extn246.0: SYS SC: 813086272671 3 13086272671 sc=type=Dial code=8N;, num=N callinfop->sending_complete=1 secondary_dialtone=
10:34:35 2507855659mS CMARS: FindActiveARSByGroupID GroupID=1 - Not Found
10:34:35 2507855659mS CMLRQ: FindActiveLRQByGroupID GroupID=1 - Not Found
10:34:35 2507855659mS CMCallEvt: 0000000000000000 0.93682.0 -1 BaseEP: NEW CMEndpoint f1840084 TOTAL NOW=11 CALL_LIST=4
10:34:35 2507855660mS CMTARGET: ISDN BChannel 1: in-service check = 1
10:34:35 2507855660mS CMTARGET: ISDN BChannel 1: in-service check = 1
10:34:35 2507855661mS CMTARGET: DIAL LINE: 16798 GROUP = 1 SUCCESS = f1840084
10:34:35 2507855662mS CMTARGET: c0a801fc00016df0 0.93680.0 16798 Extn246.0: INITIAL TARGETING SUCCEEDED
10:34:35 2507855662mS CMTARGET: c0a801fc00016df0 0.93680.0 16798 Extn246.0: GetNoAnswerTimer:15
10:34:35 2507855662mS CMCallEvt: c0a801fc00016df0 0.93680.0 16798 Extn246.0: StateChange: END=A CMCSDialling->CMCSDialled
10:34:35 2507855662mS CMExtnEvt: v=30 State, new=Proceeding old=Dialling,0,0,Extn246
10:34:35 2507855662mS CMExtnTx: v=246, p1=0
CMProceeding
Line: type=DigitalExtn 6 Call: lid=0 id=93680 in=0
Timed: 24/07/20 10:34
10:34:35 2507855663mS CMCallEvt: 0000000000000000 0.93681.0 16798 TargetingEP: StateChange: END=B CMCSIdle->CMCSOffering
10:34:35 2507855663mS CMCallEvt: c0a801fc00016df2 0.93682.0 16798 Q931 Trunk:5 CHAN=1: StateChange: END=T CMCSIdle->CMCSOffering
10:34:35 2507855664mS PRN: Setting configured voice gain for ch 1.
10:34:35 2507855664mS CMLineTx: v=5
CMSetup
Line: type=Q931Line 5 Call: lid=0 id=93682 in=0
Called[13086272671] Type=National (2) Reason=CMDRdirect Calling[] Type=National Plan=ISDN
BC: CMTC=Speech CMTM=CallIndSigCon CMTR=64 CMST=Default CMU1=ULaw
BChan: slot=0 chan=1
Timed: 24/07/20 10:34
Locale: enu
10:34:35 2507855664mS CD: CALL: 0.93680.0 BState=Idle Cut=1 Music=0.0 Aend="Extn246(246)" (8.32) Bend="Line 5" [Line 5] (0.0) CalledNum=813086272671 () CallingNum=246 (Extn246) Internal=0 Time=11567 AState=Dialled
10:34:35 2507855667mS ISDNL3Evt: v=5 stacknum=5 State, new=Initiated, old=NullState id=93682
10:34:35 2507855680mS ISDNL3Evt: v=5 stacknum=5 State, new=Proceeding, old=Initiated id=93682
10:34:35 2507855681mS CMLineRx: v=5
CMProceeding
Line: type=Q931Line 5 Call: lid=0 id=93682 in=0
BChan: slot=0 chan=1
10:34:35 2507855681mS CMCallEvt: 0000000000000000 0.93681.0 16798 TargetingEP: RequestEnd c0a801fc00016df2 0.93682.0 16798 Q931 Trunk:5 CHAN=1
10:34:35 2507855681mS CMTARGET: c0a801fc00016df0 0.93680.0 16798 Extn246.0: CancelTimer CMTCNoAnswerTimeout
10:34:35 2507855682mS CMCallEvt: 0000000000000000 0.93681.0 -1 BaseEP: DELETE CMEndpoint f4f703d8 TOTAL NOW=10 CALL_LIST=4
10:34:35 2507855682mS CMCallEvt: c0a801fc00016df2 0.93682.0 16798 Q931 Trunk:5 CHAN=1: StateChange: END=B CMCSOffering->CMCSAccept
10:34:35 2507855683mS CD: CALL: 0.93680.0 BState=Ringing Cut=3 Music=0.0 Aend="Extn246(246)" (8.32) Bend="Line 5" [Line 5] (3.2) CalledNum=13086272671 () CallingNum=246 (Extn246) Internal=0 Time=11586 AState=Dialled
10:34:35 2507855684mS CMMap: PCG::MapBChan pcp[258]b1r0 cp_b f4c29e08 other_cp_b 0 type CGTypeSimple
10:34:35 2507855684mS CMMap: PCG::MapBChan pcp[72]b1r0 cp_b f5527e30 other_cp_b f4c29e08 type CGTypeSimple
10:34:35 2507855684mS CMMap: a=8.32 b=3.2 M12
10:34:35 2507855766mS ISDNL3Evt: v=5 stacknum=5 State, new=ReleaseReq, old=Proceeding id=93682
10:34:35 2507855774mS ISDNL3Evt: v=5 stacknum=5 State, new=NullState, old=ReleaseReq id=93682
10:34:35 2507855775mS CMLineRx: v=5
CMReleaseComp
Line: type=Q931Line 5 Call: lid=0 id=93682 in=0
BChan: slot=0 chan=1
Cause=1, Unallocated (unassigned) number
10:34:35 2507855775mS CMCallEvt: c0a801fc00016df2 0.93682.0 16798 Q931 Trunk:5 CHAN=1: StateChange: END=B CMCSAccept->CMCSCompleted
10:34:35 2507855776mS CMLOGGING: CALL:2020/07/2410:34,00:00:00,000,246,O,13086272671,813086272671,Extn246,,,0,,"",0,n/a
10:34:35 2507855776mS CD: CALL: 0.93680.0 BState=Disconnecting Cut=1 Music=0.0 Aend="Extn246(246)" (8.32) Bend="Line 5" [Line 5] (3.2) CalledNum=13086272671 () CallingNum=246 (Extn246) Internal=0 Time=11679 AState=Dialled
10:34:35 2507855777mS CD: CALL: 0.93680.0 Deleted
10:34:35 2507855777mS CMExtnEvt: Extn246: CALL LOST (CMCauseUnallocatedNumber)
10:34:35 2507855777mS CMExtnEvt: Extn246: Extn(246) Calling Party Number(246) Type(CMNTypeInternal)
10:34:35 2507855778mS CMCallEvt: c0a801fc00016df0 0.93680.0 -1 Extn246.0: StateChange: END=X CMCSDialled->CMCSCompletedTone
10:34:35 2507855778mS CMExtnEvt: v=30 State, new=CMESCompleted old=Proceeding,0,0,Extn246
10:34:35 2507855779mS CMCallEvt: c0a801fc00016df2 0.93682.0 -1 Q931 Trunk:5 CHAN=1: StateChange: END=X CMCSCompleted->CMCSDelete
10:34:35 2507855779mS CMCallEvt: END CALL:16798 (f4cf4d70)
10:34:35 2507855779mS CMTARGET: ISDN BChannel 1: in-service check = 1
10:34:35 2507855780mS CMTARGET: ISDN BChannel 1: in-service check = 1
10:34:35 2507855780mS CMCallEvt: c0a801fc00016df2 0.93682.0 -1 BaseEP: DELETE CMEndpoint f1840084 TOTAL NOW=9 CALL_LIST=3
10:34:35 2507855781mS CMMap: PCG::UnmapBChan pcp[258]b1r0 cp_b f4c29e08 other_cp_b f5527e30
10:34:35 2507855781mS CMMap: a=3.2 b=8.32 M02
10:34:35 2507855781mS CMMap: PCG::UnmapBChan pcp[72]b1r0 cp_b f5527e30 other_cp_b 0
10:34:35 2507855782mS CMMap: a=21.11 b=0.0 DTMF::AllocateRAS allocated CMRTVoicemail(f556a5c0) resource busy 2, total 45
10:34:35 2507855782mS CMMap: a=21.11 b=1.65535 T
10:34:35 2507855783mS CMMap: a=21.11 b=8.32 M22
10:34:36 2507856119mS RES: Fri 24/7/2020 10:34:37 FreeMem=52503004 Heap=51768932(2) Cache=734072 MemObjs=18261(18733) CMMsg=6(7) ASN=0 Buff=5200 1326 1000 7404 5 Links=69946(70139) BTree=2036(4750) CPU=05.00% CPUStats=04.35%/1/5/811/12993/14472/00.07%/0/
02.74% MCR=0 MCW=0
10:34:36 2507856119mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=51 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=76 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1 SSA=1 TCP=20(TLS=5) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
10:34:36 2507856119mS RES4: XML MemObjs=63 PoolMem=4748404(2) FreePoolMem=4733100(0)
10:34:36 2507856119mS RES5: CLog MemObjs=4563 FreePoolMem(Objs)=1924(37) TotalMem=613700
10:34:38 2507858097mS CMExtnRx: v=246, p1=0
CMReleaseComp
Line: type=DigitalExtn 6 Call: lid=0 id=93680 in=0
10:34:38 2507858098mS CMCallEvt: c0a801fc00016df0 0.93680.0 -1 Extn246.0: StateChange: END=X CMCSCompletedTone->CMCSCompleted
10:34:38 2507858098mS CMExtnEvt: v=30 State, new=PortRecoverDelay old=CMESCompleted,0,0,Extn246
10:34:38 2507858098mS CMExtnEvt: Extn246: CALL LOST (CMCauseForceClear)
10:34:38 2507858098mS CMExtnEvt: Extn246: Extn(246) Calling Party Number(246) Type(CMNTypeInternal)
10:34:38 2507858098mS CMExtnEvt: Extn246: CMExtnHandler::SetCurrent( id: 93680->0 )
10:34:38 2507858099mS CMCallEvt: c0a801fc00016df0 0.93680.0 -1 Extn246.-1: StateChange: END=X CMCSCompleted->CMCSDelete
10:34:38 2507858099mS CMTARGET: c0a801fc00016df0 0.93680.0 -1 BaseEP: ~CMTargetHandler f4ceeba8 ep f17f35e0
10:34:38 2507858099mS CMCallEvt: c0a801fc00016df0 0.93680.0 -1 BaseEP: DELETE CMEndpoint f17f35e0 TOTAL NOW=8 CALL_LIST=3
10:34:38 2507858102mS CMMap: a=21.11 b=8.32 M02
10:34:38 2507858102mS CMMap: a=21.11 b=0.0 T0
10:34:38 2507858103mS CMMap: a=21.11 b=0.0 DTMF::~DTMF freed CMRTUnknown(f556a5c0) resource busy 1, total 45
10:34:40 2507860099mS CMExtnEvt: Extn246: Recover Timer reason=CMTRWrapUp
10:34:40 2507860099mS CMExtnEvt: v=30 State, new=Idle old=PortRecoverDelay,0,0,Extn246
10:34:40 2507860100mS CMExtnTx: v=246, p1=0
CMVoiceMailStatus
Line: type=DigitalExtn 6 Call: lid=0 id=-1 in=0
Called[Extn246 Msgs=0 Old=0 Sav=0] Type=Default (100) Reason=CMDRdirect Calling[00000000] Type=Default Plan=Default
Display [Extn246 Msgs=0]

DBrewsky · Jul 24, 2020

Can you post a trace of one of the analog lines making a call on the PRI?

--DB

Telecomboy · Jul 27, 2020

I had this happen a while back with a client. All digital phones, but with dial 8 and dial 9 being used only certain phones could dial out using the dial 8 (a PRI). I cannot remember what release they were on, but if I changed the dial 9 to go out on the PRI it went out fine from all phones. If I tried the exact set-up with dial 8, certain phones would fail to dial out. I know R9.1 was not the greatest release and you are at 9.1.6. It wouldn't be a bad idea to upgrade them to the latest R9.1.12. I upgraded the system in question and it took care of the issue. You might want to just see if you point the dial 9 to the PRI if all phones can dial out. If so, I would upgrade.

CarGoSki · Jul 28, 2020

Your ISDN L2 traces are not on. I ususally like to see L1 and L2.

Your call is here: SYS SC: 813086272671 3 13086272671 sc=type=Dial code=8N;, num=N callinfop->sending_complete=1 secondary_dialtone=

Can see here where call is sent to line 5:CD: CALL: 0.93680.0 BState=Idle Cut=1 Music=0.0 Aend="Extn246(246)" (8.32) Bend="Line 5" [Line 5] (0.0) CalledNum=813086272671 () CallingNum=246 (Extn246) Internal=0 Time=11567 AState=Dialled

Your call did go to provider here. B end is Line 5 and B State is Ringing: CD: CALL: 0.93680.0 BState=Ringing Cut=3 Music=0.0 Aend="Extn246(246)" (8.32) Bend="Line 5" [Line 5] (3.2) CalledNum=13086272671 () CallingNum=246 (Extn246) Internal=0 Time=11586 AState=Dialled

Looks like call was rejected: Cause=1, Unallocated (unassigned) number.

Could be that you are sending the 8 with the number to the provider. If you turn on ISDN L2 traces you will see the digits sent to the provider and the ISDN messages.
I dont see the normal ARS messages I am used to seeing so I suspect that you may not be using ARS.
Make sure you default traces and turn on ISDN traces and Call\MonCM and Call\ShortCodeMessages

Tek-Tips is the largest IT community on the Internet today!

Members share and learn making Tek-Tips Forums the best source of peer-reviewed technical information on the Internet!

PRI Issues on IP Office 1

dseevers

Programmer

DBrewsky

Vendor

Telecomboy

Programmer

CarGoSki

Programmer

Similar threads

Part and Inventory Search

Sponsor