IP500 r9 - 2 PRI's - Calls fail after 6 or so calls??

[myalias09]

unique issue. IP500v2 9.0.0.829. We have a working PRI in slot 1 (network)from another carrier. We added a second PRI (fallback but tried unsuitable)in slot 2 above a Dig 8. The 1st PRI works fine without issue. We just turned up an ATT 10 channel PRI (NI2, esf,b8zs,cpe) and it works great for about 6 calls and then it will fail from then on. User gets a “Waiting for line” and we receive a CMARS_OUTOFSERVICE on the call. ATT throws their hands up and of course blames the IPO. We are sending the setup out no different than before and are successful the first 6 or so times before the circuit goes bad. I can reset the circuit and duplicate it. Anyone have this scenario happen to them? Any real suggestions on where to look?
I thought ive seen every issue. That’s why I love this job.
Traces show the end of a successful call and then the failure. After that the circuit is done till reset. My channels stay idle and then random individual channels will go out of service but not always.

10:54:28 306621253mS CMCallEvt: 0.3406.0 622 Server Room.1: StateChange: END=A CMCSOGConnReq->CMCSConnected
10:54:28 306621254mS CMTARGET: 0.3406.0 622 Server Room.1: ~CMTargetHandler f4a139a8 ep f4a20014
10:54:28 306621255mS CMCallEvt: 0.3409.0 622 Q931 Trunk:5 CHAN=10: StateChange: END=B CMCSConnReq->CMCSConnected
10:54:28 306621256mS CMLineTx: v=5
CMConnectAck
Line: type=Q931Line 5 Call: lid=0 id=3409 in=0
BChan: slot=0 chan=10
10:54:28 306621257mS CD: CALL: 0.3406.0 BState=Connected Cut=3 Music=0.0 Aend="Server Room(466)" (9.12) Bend="Line 5" [Line 5] (3.11) CalledNum=19169932100 () CallingNum=466 (Server Room) Internal=0 Time=1760 AState=Connected
10:54:28 306621257mS ISDNL1Tx: v=5 peb=5
0000 00 01 32 28 08 02 00 72 0f ..2(...r.
10:54:28 306621257mS ISDNL1Rx: v=5 peb=5
0000 00 01 01 34 ...4
10:54:28 306621257mS ISDNL2Rx: v=5 peb=5
0000 00 01 01 34 ...4
10:54:29 306622796mS CMTARGET: 0.3399.0 620 Mary Huebner.0: TimerExpired cause=CMTCCoverageTimeout
10:54:29 306622796mS CMTARGET: 0.3399.0 620 Mary Huebner.0: GetNoAnswerTimer:15
10:54:30 306623170mS PRN: Server Room: Feature Key Pressed 6CPLFeatureDrop
10:54:30 306623170mS CMCallEvt: 0.3406.0 622 Server Room.1: StateChange: END=A CMCSConnected->CMCSCompleted
10:54:30 306623171mS CMExtnEvt: v=10 State, new=PortRecoverDelay old=Connected,0,0,Server Room
10:54:30 306623173mS CMLOGGING: CALL:2014/03/0310:54,00:00:01,000,466,O,19065551212,819065551212,ServerRoom,,,0,,""n/a,0
10:54:30 306623173mS CD: CALL: 0.3406.0 BState=Connected Cut=2 Music=0.0 Aend="Server Room(466)" (9.12) Bend="Line 5" [Line 5] (3.11) CalledNum=19065551212() CallingNum=466 (Server Room) Internal=0 Time=3676 AState=Idle
10:54:30 306623173mS CD: CALL: 0.3406.0 Deleted
10:54:30 306623173mS CMExtnEvt: Server Room: CALL LOST (CMCauseNormal)
10:54:30 306623173mS CMExtnEvt: Server Room: Extn(466) Calling Party Number(466) Type(CMNTypeInternal)
10:54:30 306623174mS CMExtnEvt: Server Room: CMExtnHandler::SetCurrent( id: 3406->0 )
10:54:30 306623174mS CMCallEvt: 0.3406.0 -1 Server Room.-1: StateChange: END=X CMCSCompleted->CMCSDelete
10:54:30 306623176mS CMLineTx: v=5
CMDisconnect
Line: type=Q931Line 5 Call: lid=0 id=3409 in=0
Cause=16, Normal call clearing
10:54:30 306623176mS CMCallEvt: 0.3409.0 -1 Q931 Trunk:5 CHAN=10: StateChange: END=X CMCSConnected->CMCSCompleted
10:54:30 306623176mS CMCallEvt: END CALL:622 (f4a22b8c)
10:54:30 306623177mS CMCallEvt: 0.3406.0 -1 BaseEP: DELETE CMEndpoint f4a20014 TOTAL NOW=13 CALL_LIST=4
10:54:30 306623179mS ISDNL3Evt: v=5 stacknum=5 State, new=DiscReq, old=Active id=3409
10:54:30 306623179mS ISDNL3Tx: v=5 peb=5
ISDN Layer3 Pcol=08(Q931) Reflen=2 ref=0072(Remote)
Message Type = Disconnect
InformationElement = CAUSE
0000 08 02 80 90 ....
10:54:30 306623180mS ISDNL2Tx: v=5 peb=5
0000 00 01 34 28 08 02 00 72 45 08 02 80 90 ..4(...rE....
10:54:30 306623180mS CMMap: PCG::UnmapBChan pcp[109]b1r0 cp_b f545f738 other_cp_b f53a5e48
10:54:30 306623180mS CMMap: a=9.12 b=3.11 M02
10:54:30 306623181mS CMMap: PCG::UnmapBChan pcp[172]b1r0 cp_b f53a5e48 other_cp_b 0
10:54:30 306623181mS ISDNL1Tx: v=5 peb=5
0000 00 01 34 28 08 02 00 72 45 08 02 80 90 ..4(...rE....
10:54:30 306623186mS ISDNL1Rx: v=5 peb=5
0000 00 01 01 36 ...6
10:54:30 306623186mS ISDNL2Rx: v=5 peb=5
0000 00 01 01 36 ...6
10:54:30 306623191mS ISDNL1Rx: v=5 peb=5
0000 02 01 28 36 08 02 80 72 4d ..(6...rM
10:54:30 306623191mS ISDNL2Rx: v=5 peb=5
0000 02 01 28 36 08 02 80 72 4d ..(6...rM
10:54:30 306623191mS ISDNL3Rx: v=5 peb=5
ISDN Layer3 Pcol=08(Q931) Reflen=2 ref=0072(Local)
Message Type = Release
10:54:30 306623191mS ISDNL3Tx: v=5 peb=5
ISDN Layer3 Pcol=08(Q931) Reflen=2 ref=0072(Remote)
Message Type = ReleaseComplete
10:54:30 306623191mS ISDNL2Tx: v=5 peb=5
0000 00 01 36 2a 08 02 00 72 5a ..6*...rZ
10:54:30 306623192mS ISDNL3Evt: v=5 stacknum=5 State, new=NullState, old=DiscReq id=3409
10:54:30 306623192mS CMLineRx: v=5
CMReleaseComp
Line: type=Q931Line 5 Call: lid=0 id=3409 in=0
BChan: slot=0 chan=10
10:54:30 306623192mS CMCallEvt: 0.3409.0 -1 Q931 Trunk:5 CHAN=10: StateChange: END=X CMCSCompleted->CMCSDelete
10:54:30 306623193mS CMTARGET: ISDN BChannel 10: in-service check = 1
10:54:30 306623193mS CMTARGET: ISDN BChannel 10: in-service check = 1
10:54:30 306623193mS CMCallEvt: 0.3409.0 -1 BaseEP: DELETE CMEndpoint f49ec2b8 TOTAL NOW=12 CALL_LIST=4
10:54:30 306623196mS ISDNL1Tx: v=5 peb=5
0000 00 01 36 2a 08 02 00 72 5a ..6*...rZ
10:54:30 306623196mS ISDNL1Rx: v=5 peb=5
0000 00 01 01 38 ...8
10:54:30 306623196mS ISDNL2Rx: v=5 peb=5
0000 00 01 01 38 ...8
10:54:31 306624092mS CMCallEvt: DCPLFieldBasedDisplayScreen::SetLine - Invalid line number (255(line_num) >= 4(op_line_count)) or Null buffer (text=f07a04e4)
10:54:31 306624360mS CMCallEvt: 0.3410.0 -1 BaseEP: NEW CMEndpoint f4a20014 TOTAL NOW=13 CALL_LIST=4
10:54:31 306624360mS CMCallEvt: 0.3410.0 -1 Server Room.-1: NEW CMExtnEndpoint f4a20014, Name=Server Room, Extn=466, Phys Extn=466
10:54:31 306624360mS CMCallEvt: CREATE CALL:623 (f4a22b8c)
10:54:31 306624360mS CMCallEvt: 0.3411.0 -1 BaseEP: NEW CMEndpoint f49a06a4 TOTAL NOW=14 CALL_LIST=4
10:54:31 306624361mS CMExtnEvt: Server Room: CMExtnHandler::SetCurrent( id: 0->3410 )
10:54:31 306624362mS CMExtnEvt: v=10 State, new=Idle old=PortRecoverDelay,0,0,Server Room
10:54:31 306624363mS CMExtnRx: v=466, p1=0
CMSetup
Line: type=DigitalExtn 7 Call: lid=0 id=3410 in=0
Called[819065551212] Type=Default (100) Reason=CMDRdirect SndComp Calling[466] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=Server Room
IE CMIECallingPartyKName (226)(Type=CMNameDefault) name=Server Room
10:54:31 306624363mS CMCallEvt: 0.3410.0 623 Server Room.1: StateChange: END=A CMCSIdle->CMCSDialInitiated
10:54:31 306624363mS CMExtnEvt: v=10 State, new=Dialling old=Idle,0,0,Server Room
10:54:31 306624364mS CMTARGET: 0.3410.0 623 Server Room.1: LOOKUP CALL ROUTE: type=100 called_party=819065551212 sub= calling=466 dir=out complete=1 ses=0
10:54:31 306624364mS CMTARGET: 0.3410.0 623 Server Room.1: ADD TARGET (N): number=819065551212 type=100 depth=1 nobar=1 setorig=1 ses=0
10:54:31 306624364mS CMTARGET: 0.3410.0 623 Server Room.1: SYS SC: 819065551212 2 19065551212 sc=type=Dial code=8N, num=N callinfop->sending_complete=1 secondary_dialtone=
10:54:31 306624365mS CMARS: FindActiveARSByGroupID GroupID=50 - Found
10:54:31 306624365mS CMARS: MakeCallTarget - Called Number: 19065551212
10:54:31 306624365mS CMCallEvt: 0.3412.0 -1 BaseEP: NEW CMEndpoint f4a2a724 TOTAL NOW=15 CALL_LIST=5
10:54:31 306624366mS CMTARGET: 0.3410.0 623 Server Room.1: INITIAL TARGETING SUCCEEDED
10:54:31 306624366mS CMTARGET: 0.3410.0 623 Server Room.1: GetNoAnswerTimer:15
10:54:31 306624366mS CMCallEvt: 0.3410.0 623 Server Room.1: StateChange: END=A CMCSDialInitiated->CMCSDialled
10:54:31 306624367mS CMExtnEvt: v=10 State, new=Proceeding old=Dialling,0,0,Server Room
10:54:31 306624367mS CMExtnTx: v=466, p1=0
CMProceeding
Line: type=DigitalExtn 7 Call: lid=0 id=3410 in=0
Timed: 03/03/14 10:54
10:54:31 306624367mS CMCallEvt: 0.3411.0 623 TargetingEP: StateChange: END=B CMCSIdle->CMCSOffering
10:54:31 306624368mS CMCallEvt: 0.3412.0 623 ARS for Main: StateChange: END=T CMCSIdle->CMCSOffering
10:54:31 306624368mS CMCallEvt: 0.3411.0 623 TargetingEP: RequestEnd 0.3412.0 623 ARS for Main
10:54:31 306624368mS CMTARGET: 0.3410.0 623 Server Room.1: CancelTimer CMTCNoAnswerTimeout
10:54:31 306624369mS CMCallEvt: 0.3412.0 623 ARS for Main: StateChange: END=B CMCSOffering->CMCSOverlapRecv
10:54:31 306624370mS CMARS: FORM: Main - Received Number: 19065551212
10:54:31 306624370mS CMARS: FOUND A SHORT CODE - short_code: 1N; - Tel: 1N - Called_Party: 19065551212 - Line Group Id: 0
10:54:31 306624370mS CMARS: FindActiveARSByGroupID GroupID=0 - Not Found
10:54:31 306624370mS CMLRQ: FindActiveLRQByGroupID GroupID=0 - Not Found
10:54:31 306624370mS CMTARGET: Group Id: 0 has NOT been found in Line: 1
10:54:31 306624370mS CMCallEvt: 0.3413.0 -1 BaseEP: NEW CMEndpoint f49ec2b8 TOTAL NOW=16 CALL_LIST=5
10:54:31 306624371mS CMTARGET: ISDN BChannel 9: in-service check = 1
10:54:31 306624371mS CMTARGET: ISDN BChannel 9: in-service check = 1
10:54:31 306624375mS CMARS: FOUND LINE - Line Id: 5 - using line group id: 0 - Called Number: 19065551212 - Calling Number: 466
10:54:31 306624375mS CMARS: SEND Setup TO LINE
10:54:31 306624375mS CMCallEvt: 0.3413.0 623 Q931 Trunk:5 CHAN=9: StateChange: END=child CMCSIdle->CMCSOffering
10:54:31 306624375mS PRN: Setting configured voice gain for ch 9.
10:54:31 306624376mS CMLineTx: v=5
CMSetup
Line: type=Q931Line 5 Call: lid=0 id=3413 in=0
Called[19065551212] Type=Unknown (0) Reason=CMDRdirect Calling[7172932199] Type=National Plan=ISDN
BC: CMTC=3K1Audio CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw
BChan: slot=0 chan=9
Locale: enu
10:54:31 306624376mS CMCallEvt: 0.3411.0 -1 TargetingEP: StateChange: END=X CMCSOffering->CMCSDelete
10:54:31 306624376mS CMCallEvt: 0.3411.0 -1 BaseEP: DELETE CMEndpoint f49a06a4 TOTAL NOW=15 CALL_LIST=5
10:54:31 306624378mS CD: CALL: 0.3410.0 BState=Idle Cut=3 Music=0.0 Aend="Server Room(466)" (9.12) Bend="" [Line 5] (0.0) CalledNum=819065551212 () CallingNum=466 (Server Room) Internal=1 Time=18 AState=Dialled
10:54:31 306624380mS ISDNL3Evt: v=5 stacknum=5 State, new=Initiated, old=NullState id=3413
10:54:31 306624381mS ISDNL3Tx: v=5 peb=5
ISDN Layer3 Pcol=08(Q931) Reflen=2 ref=0073(Remote)
Message Type = Setup
InformationElement = BearerCapability
0000 04 03 90 90 a2 .....
InformationElement = CHI
0000 18 03 a9 83 89 .....
InformationElement = CallingPartyNumber
0000 6c 0c 21 80 37 30 37 32 39 33 32 30 37 33 l.!.7172932199
InformationElement = CalledPartyNumber
0000 70 0c 80 31 39 31 36 39 39 33 32 31 30 30 p..19065551212
10:54:31 306624381mS ISDNL2Tx: v=5 peb=5
0000 00 01 38 2a 08 02 00 73 05 04 03 90 90 a2 18 03 ..8*...s........
0010 a9 83 89 6c 0c 21 80 37 30 37 32 39 33 32 30 37 ...l.!.717293219
0020 33 70 0c 80 31 39 31 36 39 39 33 32 31 30 30 9p..19065551212
10:54:31 306624391mS ISDNL1Tx: v=5 peb=5
0000 00 01 38 2a 08 02 00 73 05 04 03 90 90 a2 18 03 ..8*...s........
0010 a9 83 89 6c 0c 21 80 37 30 37 32 39 33 32 30 37 ...l.!.717293219
0020 33 70 0c 80 31 39 31 36 39 39 33 32 31 30 30 9p..19065551212
10:54:31 306624601mS RES: Mon 3/3/2014 10:54:31 FreeMem=50271788 49666228(1) CachedMem=605560 CMMsg=7(9) Buff=5200 1343 999 7383 5 Links=24390 BTree=13171 CPU=04.99% CPUStats=9/19/3726/8133/8995/0/1 MCR=0 MCW=0
10:54:31 306624601mS RES2: IP 500 V2 9.0.0.0 build 829 Tasks=58 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=85 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=21(TLS=4) TAPI=1 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
10:54:31 306624601mS RES4: XML MemObjs=56 PoolMem=2097152(1) FreeMem=2081932(1)
10:54:31 306624825mS ISDNL1Rx: v=1 peb=1
0000 02 01 01 0b ....
10:54:31 306624825mS ISDNL2Rx: v=1 peb=1
0000 02 01 01 0b ....
10:54:31 306624825mS ISDNL2Tx: v=1 peb=1
0000 02 01 01 9d ....
10:54:31 306624826mS ISDNL1Tx: v=1 peb=1
0000 02 01 01 9d ....
10:54:32 306625531mS ISDNL2Tx: v=5 peb=5
0000 00 01 01 2b ...+
10:54:32 306625536mS ISDNL1Tx: v=5 peb=5
0000 00 01 01 2b ...+
10:54:32 306625536mS ISDNL1Rx: v=5 peb=5
0000 00 01 01 39 ...9
10:54:32 306625536mS ISDNL2Rx: v=5 peb=5
0000 00 01 01 39 ...9
10:54:32 306625536mS ISDNL2Tx: v=5 peb=5
0000 00 01 38 2a 08 02 00 73 05 04 03 90 90 a2 18 03 ..8*...s........
0010 a9 83 89 6c 0c 21 80 37 30 37 32 39 33 32 30 37 ...l.!.717293219
0020 33 70 0c 80 31 39 31 36 39 39 33 32 31 30 30 9p..19065551212
10:54:32 306625546mS ISDNL1Tx: v=5 peb=5
0000 00 01 38 2a 08 02 00 73 05 04 03 90 90 a2 18 03 ..8*...s........
0010 a9 83 89 6c 0c 21 80 37 30 37 32 39 33 32 30 37 ...l.!.717293219
0020 33 70 0c 80 31 39 31 36 39 39 33 32 31 30 30 9p..19065551212
10:54:33 306626062mS CMExtnRx: v=197, p1=0
CMReleaseComp
Line: type=DigitalExtn 6 Call: lid=0 id=3399 in=0
10:54:35 306628380mS ISDNL3Tx: v=5 peb=5
ISDN Layer3 Pcol=08(Q931) Reflen=2 ref=0073(Remote)
Message Type = Setup
InformationElement = BearerCapability
0000 04 03 90 90 a2 .....
InformationElement = CHI
0000 18 03 a9 83 89 .....
InformationElement = CallingPartyNumber
0000 6c 0c 21 80 37 30 37 32 39 33 32 30 37 33 l.!.7172932199
InformationElement = CalledPartyNumber
0000 70 0c 80 31 39 31 36 39 39 33 32 31 30 30 p..19065551212
10:54:35 306628380mS ISDNL2Tx: v=5 peb=5
0000 00 01 3a 2a 08 02 00 73 05 04 03 90 90 a2 18 03 ..:*...s........
0010 a9 83 89 6c 0c 21 80 37 30 37 32 39 33 32 30 37 ...l.!.717293219
0020 33 70 0c 80 31 39 31 36 39 39 33 32 31 30 30 9p..19065551212
10:54:35 306628386mS ISDNL1Tx: v=5 peb=5
0000 00 01 3a 2a 08 02 00 73 05 04 03 90 90 a2 18 03 ..:*...s........
0010 a9 83 89 6c 0c 21 80 37 30 37 32 39 33 32 30 37 ...l.!.717293219
0020 33 70 0c 80 31 39 31 36 39 39 33 32 31 30 30 9p..19065551212
10:54:35 306628391mS ISDNL1Rx: v=5 peb=5
0000 00 01 09 38 ...8
10:54:35 306628391mS ISDNL2Rx: v=5 peb=5
0000 00 01 09 38 ...8
10:54:35 306628391mS ISDNL2Tx: v=5 peb=5
0000 00 01 38 2a 08 02 00 73 05 04 03 90 90 a2 18 03 ..8*...s........
0010 a9 83 89 6c 0c 21 80 37 30 37 32 39 33 32 30 37 ...l.!.717293219
0020 33 70 0c 80 31 39 31 36 39 39 33 32 31 30 30 9p..19065551212
10:54:35 306628391mS ISDNL2Tx: v=5 peb=5
0000 00 01 3a 2a 08 02 00 73 05 04 03 90 90 a2 18 03 ..:*...s........
0010 a9 83 89 6c 0c 21 80 37 30 37 32 39 33 32 30 37 ...l.!.717293219
0020 33 70 0c 80 31 39 31 36 39 39 33 32 31 30 30 9p..19065551212
10:54:35 306628401mS ISDNL1Tx: v=5 peb=5
0000 00 01 38 2a 08 02 00 73 05 04 03 90 90 a2 18 03 ..8*...s........
0010 a9 83 89 6c 0c 21 80 37 30 37 32 39 33 32 30 37 ...l.!.717293219
0020 33 70 0c 80 31 39 31 36 39 39 33 32 31 30 30 9p..19065551212
10:54:35 306628411mS ISDNL1Tx: v=5 peb=5
0000 00 01 3a 2a 08 02 00 73 05 04 03 90 90 a2 18 03 ..:*...s........
0010 a9 83 89 6c 0c 21 80 37 30 37 32 39 33 32 30 37 ...l.!.717293219
0020 33 70 0c 80 31 39 31 36 39 39 33 32 31 30 30 9p..19065551212
10:54:36 306629530mS ISDNL2Tx: v=5 peb=5
0000 00 01 01 2b ...+
10:54:36 306629531mS ISDNL1Tx: v=5 peb=5
0000 00 01 01 2b ...+
10:54:36 306629536mS ISDNL1Rx: v=5 peb=5
0000 00 01 01 39 ...9
10:54:36 306629536mS ISDNL2Rx: v=5 peb=5
0000 00 01 01 39 ...9
10:54:36 306629536mS ISDNL2Tx: v=5 peb=5
0000 00 01 38 2a 08 02 00 73 05 04 03 90 90 a2 18 03 ..8*...s........
0010 a9 83 89 6c 0c 21 80 37 30 37 32 39 33 32 30 37 ...l.!.717293219
0020 33 70 0c 80 31 39 31 36 39 39 33 32 31 30 30 9p..19065551212
10:54:36 306629536mS ISDNL2Tx: v=5 peb=5
0000 00 01 3a 2a 08 02 00 73 05 04 03 90 90 a2 18 03 ..:*...s........
0010 a9 83 89 6c 0c 21 80 37 30 37 32 39 33 32 30 37 ...l.!.717293219
0020 33 70 0c 80 31 39 31 36 39 39 33 32 31 30 30 9p..19065551212
10:54:36 306629546mS ISDNL1Tx: v=5 peb=5
0000 00 01 38 2a 08 02 00 73 05 04 03 90 90 a2 18 03 ..8*...s........
0010 a9 83 89 6c 0c 21 80 37 30 37 32 39 33 32 30 37 ...l.!.717293219
0020 33 70 0c 80 31 39 31 36 39 39 33 32 31 30 30 9p..19065551212
10:54:36 306629556mS ISDNL1Tx: v=5 peb=5
0000 00 01 3a 2a 08 02 00 73 05 04 03 90 90 a2 18 03 ..:*...s........
0010 a9 83 89 6c 0c 21 80 37 30 37 32 39 33 32 30 37 ...l.!.717293219
0020 33 70 0c 80 31 39 31 36 39 39 33 32 31 30 30 9p..19065551212
10:54:38 306632380mS ISDNL3Evt: v=5 stacknum=5 State, new=NullState, old=Initiated id=3413
10:54:38 306632380mS ISDNL3Tx: v=5 peb=5
ISDN Layer3 Pcol=08(Q931) Reflen=2 ref=0073(Remote)
Message Type = ReleaseComplete
InformationElement = CAUSE
0000 08 02 80 9f ....
10:54:38 306632380mS ISDNL2Tx: v=5 peb=5
0000 00 01 3c 2a 08 02 00 73 5a 08 02 80 9f ..<*...sZ....
10:54:38 306632381mS ISDNL1Tx: v=5 peb=5
0000 00 01 3c 2a 08 02 00 73 5a 08 02 80 9f ..<*...sZ....
10:54:38 306632381mS CMLineRx: v=5
CMReleaseComp
Line: type=Q931Line 5 Call: lid=0 id=3413 in=0
BChan: slot=0 chan=9
10:54:38 306632381mS CMARS: LINE ep Received: CMReleaseComp - child->state = CMCSOffering - ARS Call State = CMCSOverlapRecv
10:54:38 306632382mS CMLineTx: v=5
CMDisconnect
Line: type=Q931Line 5 Call: lid=0 id=3413 in=0
Cause=16, Normal call clearing
10:54:38 306632382mS CMCallEvt: 0.3413.0 -1 Q931 Trunk:5 CHAN=9: StateChange: END=X CMCSOffering->CMCSCompleted
10:54:38 306632383mS CMARS: Target: Short_Code: 1N; - Line_Group_ID: 0 has been set to: CMARS_OUTOFSERVICE
10:54:38 306632383mS CMCallEvt: 0.3412.0 623 ARS for Main: StateChange: END=B CMCSOverlapRecv->CMCSAccept
10:54:38 306632383mS CMCallEvt: 0.3410.0 623 Server Room.1: StateChange: END=A CMCSDialled->CMCSRingBack
10:54:38 306632384mS CMExtnEvt: v=10 State, new=Alerting old=Proceeding,0,0,Server Room
10:54:38 306632384mS CMExtnTx: v=466, p1=0
CMProgress
Line: type=DigitalExtn 7 Call: lid=0 id=3410 in=0
IE CMIEProgressIndicator (30) cs=CMCSITUT (0), loc=CMLUser (0), pd=CMPDInbandPattern (8)
Display [WAITING_FOR_LINE]
Timed: 03/03/14 10:54
10:54:38 306632385mS CD: CALL: 0.3410.0 BState=Ringing Cut=3 Music=0.0 Aend="Server Room(466)" (9.12) Bend="" [] (0.0) CalledNum=819065551212 () CallingNum=466 (Server Room) Internal=1 Time=8025 AState=Ringing
10:54:38 306632387mS CMMap: a=21.42 b=0.0 DTMF::AllocateRAS allocated CMRTVoicemail resource busy 1, total 45
10:54:38 306632387mS CMMap: a=21.42 b=1.255 T
10:54:38 306632387mS CMMap: PCG::MapBChan pcp[172]b1r0 cp_b f53a5e48 other_cp_b f54c8748 type CGTypeDTMF
10:54:38 306632388mS CMMap: a=21.42 b=9.12 M22
10:54:38 306632388mS CMMap: DTMF:layTones g T[596] ,EEEEE
10:54:38 306632388mS CMMap: Started playing tones, cp[172]b1r0 (from g null)
10:54:38 306632388mS CMMap: cp[172]b1r0 SetOperGroup from g null to g null not executed, playing tones in progress ,EEEEE
10:54:38 306632388mS CMLineRx: v=5
CMReleaseComp

 

[intrigrant]

The failing call is because the operator does not respond on the send call setup message, i see only TX messages and no RX from operator.
So let them explain...

 

[fshaw]

Flip flop the pris (and programming) and confirm that the problem moves with the circuit. This will give you a simple concrete isolation of the issue. Then have them follow Intrigrant's analysis if it follows the pri.

 

[myalias09]

agreed, but the carrier is digging their head in the sand. They are using a Cisco 3945 router and nobody seems to know how to figure it or have any answers. Typical, they are just telling the customer it is the phone system and brush it away.

 

[smokinjoe2938]

time to find a new provider then

acss sme acis sme acss cm 5.2.1 acss cm and cmm acss aura messaging.