Thanks again. It does look like it's sending out of the IP Office.
56351179mS CMExtnRxP: v=3214
CMSetup
Line: type=NoLine 0 Call: lid=0 id=-1 in=0
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw
56351180mS CMCallEvt: 0.1716.0 -1 BaseEP: NEW CMEndpoint fe948180 TOTAL NOW=7 CALL_LIST=3
56351180mS CMCallEvt: 0.1716.0 -1 Steven Lucente.-1: NEW CMExtnEndpoint fe948180, Name=Steven Lucente, Extn=3214, Phys Extn=3214
56351180mS CMCallEvt: CREATE CALL:207 (fe99b834)
56351181mS CMCallEvt: 0.1717.0 -1 BaseEP: NEW CMEndpoint fe9ac12c TOTAL NOW=8 CALL_LIST=3
56351185mS CMExtnEvt: Steven Lucente: CMExtnHandler::SetCurrent( id: 0->1716 )
56351189mS CMExtnRx: v=3214, p1=0
CMSetup
Line: type=DigitalExtn 4 Call: lid=0 id=1716 in=0
Called[] Type=Default (100) Reason=CMDRdirect Calling[3214] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=Steven Lucente
IE CMIECallingPartyKName (226)(Type=CMNameDefault) name=Steven Lucente
56351190mS CMExtnCopyProcessMsg: v=4
CMSetup
Line: type=DigitalExtn 4 Call: lid=0 id=1716 in=0
Called[] Type=Default (100) Reason=CMDRdirect Calling[3214] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw
BChan: slot=10 chan=6
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=Steven Lucente
IE CMIECallingPartyKName (226)(Type=CMNameDefault) name=Steven Lucente
56351190mS CMCallEvt: 0.1716.0 207 Steven Lucente.0: StateChange: END=A CMCSIdle->CMCSDialInitiated
56351191mS CMExtnEvt: v=4 State, new=Connected old=Idle,0,0,Steven Lucente
56351192mS CMTARGET: 0.1716.0 207 Steven Lucente.0: LOOKUP CALL ROUTE: type=100 called_party= sub= calling=3214 dir=out complete=0 ses=0
56351192mS CMTARGET: 0.1716.0 207 Steven Lucente.0: ADD TARGET (N): number= type=100 depth=1 nobar=1 setorig=1 ses=0
56351193mS CMCallEvt: 0.1716.0 207 Steven Lucente.0: StateChange: END=A CMCSDialInitiated->CMCSDialling
56351194mS CMExtnEvt: v=4 State, new=Dialling old=Connected,0,0,Steven Lucente
56351195mS CMExtnCopyProcessCallMsg: v=4
CMSetupAck
Line: type=NoLine 0 Call: lid=0 id=1716 in=0
56351195mS CMExtnTxP: v=3214
CMSetupAck
Line: type=DigitalExtn 4 Call: lid=0 id=1716 in=0
BChan: slot=10 chan=6
Timed: 28/07/10 14:36
56351195mS CMExtnTx: v=3214, p1=0
CMSetupAck
Line: type=DigitalExtn 4 Call: lid=0 id=1716 in=0
BChan: slot=10 chan=6
Timed: 28/07/10 14:36
56351198mS CMMap: a=10.6 b=0.0 D1
56351199mS CD: CALL: 0.1716.0 BState=Idle Cut=1 Music=3.0 Aend="Steven Lucente(3214)" (10.6) Bend="" [] (0.0) CalledNum= () CallingNum=3214 (Steven Lucente) Internal=1 Time=19 AState=DialInitiated
56351257mS CMExtnRxP: v=3214
CMInformation
Line: type=NoLine 0 Call: lid=0 id=-1 in=0
Called[901131627210747] Type=Default (100) Reason=CMDRdirect
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw
56351258mS CMTARGET: 0.1716.0 207 Steven Lucente.0: Setting Hard Timer 4000
56351258mS CMTARGET: 0.1716.0 207 Steven Lucente.0: LOOKUP CALL ROUTE: type=100 called_party=901131627210747 sub= calling=3214 dir=out complete=0 ses=0
56351258mS CMTARGET: 0.1716.0 207 Steven Lucente.0: ADD TARGET (N): number=901131627210747 type=100 depth=1 nobar=1 setorig=1 ses=0
56351259mS CMTARGET: 0.1716.0 207 Steven Lucente.0: SYS SC: 901131627210747 2 01131627210747 sc=type=Dial code=9N, num=N callinfop->sending_complete=0 secondary_dialtone=
56351260mS CMARS: FindActiveARSByGroupID GroupID=50 - Found
56351260mS CMARS: MakeCallTarget - Called Number: 01131627210747
56351261mS CMCallEvt: 0.1718.0 -1 BaseEP: NEW CMEndpoint fe98ab58 TOTAL NOW=9 CALL_LIST=4
56351261mS CMTARGET: 0.1716.0 207 Steven Lucente.0: CancelTimer CMTCDelayedProcessing
56351261mS CMTARGET: 0.1716.0 207 Steven Lucente.0: INITIAL TARGETING SUCCEEDED
56351262mS CMTARGET: 0.1716.0 207 Steven Lucente.0: GetNoAnswerTimer:25
56351264mS CMCallEvt: 0.1717.0 207 TargetingEP: StateChange: END=B CMCSIdle->CMCSOffering
56351265mS CMCallEvt: 0.1718.0 207 ARS for Main: StateChange: END=T CMCSIdle->CMCSOffering
56351266mS CMCallEvt: 0.1717.0 207 TargetingEP: RequestEnd 0.1718.0 207 ARS for Main
56351266mS CMTARGET: 0.1716.0 207 Steven Lucente.0: CancelTimer CMTCNoAnswerTimeout
56351266mS CMCallEvt: 0.1718.0 207 ARS for Main: StateChange: END=B CMCSOffering->CMCSOverlapRecv
56351267mS CMARS: FORM: Main - Received Number: 01131627210747
56351267mS CMARS: CMARSTargetingPending
56351267mS CMCallEvt: 0.1717.0 -1 TargetingEP: StateChange: END=X CMCSOffering->CMCSDelete
56351268mS CMCallEvt: 0.1717.0 -1 BaseEP: DELETE CMEndpoint fe9ac12c TOTAL NOW=8 CALL_LIST=4
56351271mS CMMap: a=10.6 b=0.0 D0
56351280mS CD: CALL: 0.1716.0 BState=Idle Cut=2 Music=0.0 Aend="Steven Lucente(3214)" (10.6) Bend="" [] (0.0) CalledNum=901131627210747 () CallingNum=3214 (Steven Lucente) Internal=1 Time=100 AState=Dialling
56351666mS RES: Wed 28/7/2010 14:36:27 FreeMem=38053792(2) CMMsg=4 (5) Buff=100 568 498 1068 3 Links=4482
56351667mS RES2: IP 406 DS 5.0(8) Tasks=25 RTEngine=0 CMRTEngine=0 Timer=65 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2
56353993mS PRN: WAV Hold Music HoldMusic.wav failed to load
56353993mS PRN: Deleted WAV file MOH Source 1
56355261mS CMARS: Case 1 - dial_delay_time: 4000 has expired - Resolve what we might have - Called Number: 01131627210747 Addr: fe98ab58
56355262mS CMARS: FORM: Main - Received Number: 01131627210747
56355262mS CMARS: FOUND A SHORT CODE - short_code: 0N; - Tel: 0N - Called_Party: 01131627210747 - Line Group Id: 0
56355263mS CMARS: CMARSTargetingFailed
56355263mS CMARS: FAIL CALL
56355263mS CMARS: 0.1718.0 207 ARS for Main: DropCall() - ABOUT TO SEND CMReleaseComp
56355263mS CMCallEvt: 0.1718.0 207 ARS for Main: StateChange: END=B CMCSOverlapRecv->CMCSCompleted
56355264mS CMLOGGING: CALL:2010/07/2814:36,00:00:00,000,3214,O,901131627210747,901131627210747,StevenLucente,,,1,,""n/a,0
56355265mS CD: CALL: 0.1716.0 BState=Disconnecting Cut=0 Music=0.0 Aend="Steven Lucente(3214)" (10.6) Bend="" [] (0.0) CalledNum=901131627210747 () CallingNum=3214 (Steven Lucente) Internal=1 Time=4085 AState=Dialling
56355266mS CD: CALL: 0.1716.0 Deleted
56355269mS CMExtnEvt: Steven Lucente: CALL LOST (CMCauseCallBarred)
56355269mS CMExtnEvt: Steven Lucente: Extn(3214) Calling Party Number(3214) Type(CMNTypeInternal)
56355270mS CMCallEvt: 0.1716.0 -1 Steven Lucente.0: StateChange: END=X CMCSDialling->CMCSCompletedTone
56355270mS CMExtnEvt: v=4 State, new=CMESCompleted old=Dialling,0,0,Steven Lucente
56355271mS CMExtnCopyCallLostMsg: v=4
CMReleaseComp
Line: type=NoLine 0 Call: lid=0 id=1716 in=0
Cause=17, User busy
56355272mS CMARS: CMARSEndpoint::CallLost(cause=122) - Address: 0.1718.0 -1 ARS for Main - Call State: CMCSCompleted
56355272mS CMCallEvt: 0.1718.0 -1 ARS for Main: StateChange: END=X CMCSCompleted->CMCSDelete
56355272mS CMCallEvt: END CALL:207 (fe99b834)
56355275mS CMCallEvt: 0.1718.0 -1 BaseEP: DELETE CMEndpoint fe98ab58 TOTAL NOW=7 CALL_LIST=3
56355277mS CMMap: a=5.6 b=0.0 DTMF::AllocateRAS allocated CMRTTonegen resource busy 6, total 8
56355277mS CMMap: a=5.6 b=1.255 T
56355278mS CMMap: a=5.6 b=10.6 M2