texmatlock
Programmer
Can anyone tell me, based on this trace, why calls across SCN are failing with error code 17?
Any help as always much appreciated.
0:58:45 2506273mS PRN: 421: Digit Pressed 2
10:58:45 2506274mS CMCallEvt: 0.1039.0 -1 BaseEP: NEW CMEndpoint f4f4b604 TOTAL NOW=1 CALL_LIST=0
10:58:45 2506274mS CMCallEvt: 0.1039.0 -1 Ext421.-1: NEW CMExtnEndpoint f4f4b604, Name=Ext421, Extn=421, Phys Extn=421
10:58:45 2506275mS CMCallEvt: CREATE CALL:13 (f4f4a0ec)
10:58:45 2506275mS CMCallEvt: 0.1040.0 -1 BaseEP: NEW CMEndpoint f5767c6c TOTAL NOW=2 CALL_LIST=0
10:58:45 2506277mS CMExtnEvt: Ext421: CMExtnHandler::SetCurrent( id: 0->1039 )
10:58:45 2506278mS CMExtnRx: v=421, p1=0
CMSetup
Line: type=IPLine 250 Call: lid=251 id=1039 in=0
Called[] Type=Default (100) Reason=CMDRdirect Calling[421] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw
IE CMIEFastStartInfoData (6) 10 item(s)
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=Ext421
10:58:45 2506278mS CMCallEvt: 251.1039.0 13 Ext421.0: StateChange: END=A CMCSIdle->CMCSDialInitiated
10:58:45 2506278mS CMExtnEvt: v=2 State, new=Dialling old=Idle,0,0,Ext421
10:58:45 2506278mS CMTARGET: 251.1039.0 13 Ext421.0: LOOKUP CALL ROUTE: type=100 called_party= sub= calling=421 dir=out complete=0 ses=0
10:58:45 2506279mS CMTARGET: 251.1039.0 13 Ext421.0: ADD TARGET (N): number= type=100 depth=1 nobar=1 setorig=1 ses=0
10:58:45 2506279mS CMCallEvt: 251.1039.0 13 Ext421.0: StateChange: END=A CMCSDialInitiated->CMCSDialling
10:58:45 2506282mS CMExtnTx: v=421, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=251 id=1039 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
IE CMIESecurityData (253) 2 item(s)
Timed: 25/09/14 10:58
10:58:45 2506282mS CMExtnTx: v=421, p1=8000
CMFacility
Line: type=IPLine 250 Call: lid=251 id=2 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
10:58:45 2506282mS CMExtnTx: v=421, p1=0
CMSetupAck
Line: type=IPLine 250 Call: lid=251 id=1039 in=0
Timed: 25/09/14 10:58
10:58:45 2506283mS CMExtnRx: v=421, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=251 id=1039 in=0
Called[2] Type=Default (100) Reason=CMDRdirect Keypad[2]
10:58:45 2506283mS CMTARGET: 251.1039.0 13 Ext421.0: Setting Hard Timer 4000
10:58:45 2506283mS CMTARGET: 251.1039.0 13 Ext421.0: LOOKUP CALL ROUTE: type=100 called_party=2 sub= calling=421 dir=out complete=0 ses=0
10:58:45 2506283mS CMTARGET: 251.1039.0 13 Ext421.0: ADD TARGET (N): number=2 type=100 depth=1 nobar=1 setorig=1 ses=0
10:58:45 2506286mS CD: CALL: 251.1039.0 BState=Idle Cut=0 Music=0.0 Aend="Ext421(421)" (0.0) Bend="" [] (0.0) CalledNum=2 () CallingNum=421 (Ext421) Internal=1 Time=11 AState=Dialling
10:58:45 2506288mS H323Evt: SetOperational 13 192.168.49.10:0 to 0
10:58:45 2506717mS RES: Thu 25/9/2014 10:58:45 FreeMem=54574844 54274012(2) CachedMem=300832 CMMsg=5(6) Buff=5200 1362 1000 7463 5 Links=6639 BTree=14264 CPU=03.95% CPUStats=1/3/16300/25502/25810/0/0 MCR=0 MCW=0
10:58:45 2506717mS RES2: IP 500 V2 9.0.0.0 build 829 Tasks=50 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=62 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=21(TLS=4) TAPI=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
10:58:45 2506717mS RES4: XML MemObjs=56 PoolMem=2097152(1) FreeMem=2081932(1)
10:58:45 2506893mS PRN: 421: Digit Pressed 2
10:58:45 2506893mS CMExtnRx: v=421, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=251 id=1039 in=0
Called[2] Type=Default (100) Reason=CMDRdirect Keypad[2]
10:58:45 2506894mS CMTARGET: 251.1039.0 13 Ext421.0: Setting Hard Timer 4000
10:58:45 2506894mS CMTARGET: 251.1039.0 13 Ext421.0: LOOKUP CALL ROUTE: type=100 called_party=22 sub= calling=421 dir=out complete=0 ses=0
10:58:45 2506894mS CMTARGET: 251.1039.0 13 Ext421.0: ADD TARGET (N): number=22 type=100 depth=1 nobar=1 setorig=1 ses=0
10:58:47 2508533mS PRN: 421: Digit Pressed 1
10:58:47 2508533mS CMExtnRx: v=421, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=251 id=1039 in=0
Called[1] Type=Default (100) Reason=CMDRdirect Keypad[1]
10:58:47 2508534mS CMTARGET: 251.1039.0 13 Ext421.0: Setting Hard Timer 4000
10:58:47 2508534mS CMTARGET: 251.1039.0 13 Ext421.0: LOOKUP CALL ROUTE: type=100 called_party=221 sub= calling=421 dir=out complete=0 ses=0
10:58:47 2508534mS CMTARGET: 251.1039.0 13 Ext421.0: ADD TARGET (N): number=221 type=100 depth=1 nobar=1 setorig=1 ses=0
10:58:47 2508534mS CMTARGET: 251.1039.0 13 Ext421.0: SET USER: J Mendez orig=1
10:58:47 2508534mS CMTARGET: 251.1039.0 13 Ext421.0: ADD USER: J Mendez depth=1 disallow_cw=0 dnd=0 real_call=1 group_call=0 type(CMNTypeDefault) incl(0x0) excpt(0x0), allow_redir(0) remote=c0a8270d simult 0 (0)
10:58:47 2508534mS CMTARGET: 251.1039.0 13 Ext421.0: Direct to Remote Target: J Mendez
10:58:47 2508535mS CMTARGET: 251.1039.0 13 Ext421.0: MakeCallToNetworkedUser J Mendez simult:0 ipad=192.168.39.13 via 192.168.39.13
10:58:47 2508536mS CMCallEvt: 0.1041.0 -1 BaseEP: NEW CMEndpoint f4f3fdd4 TOTAL NOW=3 CALL_LIST=1
10:58:47 2508541mS CMTARGET: MakeCallToNetworkedPBX using line group id: 12 ipaddr=192.168.39.13
10:58:47 2508541mS CMTARGET: 251.1039.0 13 Ext421.0: Targeted OK: J Mendez
10:58:47 2508541mS CMTARGET: 251.1039.0 13 Ext421.0: CancelTimer CMTCDelayedProcessing
10:58:47 2508541mS CMTARGET: 251.1039.0 13 Ext421.0: INITIAL TARGETING SUCCEEDED
10:58:47 2508541mS CMTARGET: 251.1039.0 13 Ext421.0: GetNoAnswerTimer:25
10:58:47 2508542mS CMCallEvt: 251.1039.0 13 Ext421.0: StateChange: END=A CMCSDialling->CMCSDialled
10:58:47 2508542mS CMExtnEvt: v=2 State, new=Proceeding old=Dialling,0,0,Ext421
10:58:47 2508542mS CMExtnTx: v=421, p1=0
CMProceeding
Line: type=IPLine 250 Call: lid=251 id=1039 in=0
Timed: 25/09/14 10:58
10:58:47 2508543mS CMCallEvt: 0.1040.0 13 TargetingEP: StateChange: END=B CMCSIdle->CMCSOffering
10:58:47 2508545mS CMCallEvt: 0.1041.0 13 H323TrunkEP: StateChange: END=T CMCSIdle->CMCSOffering
10:58:47 2508546mS CMLineTx: v=18
CMSetup
Line: type=IPLine 18 Call: lid=0 id=1041 in=0
Called[221] Type=Default (100) Reason=CMDRdirect SndComp Calling[421] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw
IE CMIESupplementaryService (3)
Network Facility Extension
sourceEntity: 0
destinationEntity: 0
Interpretation APDU
discardAnyUnrecognisedInvokePdu
CallingName.Invoke.CodePageUtf8String
invokeId 14637
user 'Ext421' presentation Allowed
IE CMIEFastStartInfoData (6) 6 item(s)
IE CMIECallSignalChannelData (8) unknown
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=Ext421
IE CMIECalledPartyName (224)(Type=CMNameDefault) name=J Mendez
IE CMIECalledPartyKName (225)(Type=CMNameDefault) name=Jac Mendez
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=Ext421
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=421
IE CMIEDeviceDetail (231) LOCALE=enu HW=15 VER=9 class=CMDeviceH323Phone type=88 number=8000 channel=0 features=0x10000420 rx_gain=32 tx_gain=32 ep_callid=1039 ipaddr=192.168.49.10 apps=0 loc=0 em_loc=0 features2=0x0
IE CMIEMohSourceId (247) MOH Source = 255
Timed: 25/09/14 10:58
Locale: enu
10:58:47 2508546mS CD: CALL: 251.1039.0 BState=Idle Cut=1 Music=0.0 Aend="Ext421(421)" (0.0) Bend="J Mendez(221)" [Line 18] (0.0) CalledNum=221 (J Mendez) CallingNum=421 (Ext421) Internal=0 Time=2271 AState=Dialled
10:58:47 2508550mS H323Evt: v=0 stacknum=18 State, new=NullState, old=NullState id=-1
10:58:47 2508552mS H323Evt: v=0 stacknum=18 State, new=Initiated, old=NullState id=1041
10:58:47 2508561mS H323Evt: v=0 stacknum=18 State, new=NullState, old=Initiated id=1041
10:58:47 2508562mS CMLineRx: v=18
CMReleaseComp
Line: type=IPLine 18 Call: lid=0 id=1041 in=0
Cause=17, User busy
10:58:47 2508562mS CMCallEvt: 0.1040.0 13 TargetingEP: RequestEnd 0.1041.0 13 H323TrunkEP
10:58:47 2508562mS CMTARGET: 251.1039.0 13 Ext421.0: CancelTimer CMTCNoAnswerTimeout
10:58:47 2508562mS CMCallEvt: 0.1040.0 -1 BaseEP: DELETE CMEndpoint f5767c6c TOTAL NOW=2 CALL_LIST=1
10:58:47 2508563mS CMCallEvt: 0.1041.0 13 H323TrunkEP: StateChange: END=B CMCSOffering->CMCSCompleted
10:58:47 2508564mS CMExtnTx: v=421, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=251 id=1039 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
Timed: 25/09/14 10:58
10:58:47 2508564mS CMExtnTx: v=421, p1=8000
CMFacility
Line: type=IPLine 250 Call: lid=251 id=2 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
10:58:47 2508567mS CMLOGGING: CALL:2014/09/2510:58,00:00:00,000,421,O,221,221,Ext421,,,0,,""n/a,0
10:58:47 2508567mS CD: CALL: 251.1039.0 BState=Disconnecting Cut=1 Music=0.0 Aend="Ext421(421)" (0.0) Bend="J Mendez(221)" [Line 18] (268.1) CalledNum=221 (J Mendez) CallingNum=421 (Ext421) Internal=0 Time=2292 AState=Dialled
10:58:47 2508567mS CD: CALL: 251.1039.0 Deleted
10:58:47 2508569mS CMExtnEvt: Ext421: CALL LOST (CMCauseBusy)
10:58:47 2508569mS CMExtnEvt: Ext421: Extn(421) Calling Party Number(421) Type(CMNTypeInternal)
10:58:47 2508569mS CMCallEvt: 251.1039.0 -1 Ext421.0: StateChange: END=X CMCSDialled->CMCSCompletedTone
10:58:47 2508571mS CMExtnTx: v=421, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=251 id=1039 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
Timed: 25/09/14 10:58
10:58:47 2508571mS CMExtnTx: v=421, p1=8000
CMFacility
Line: type=IPLine 250 Call: lid=251 id=2 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
10:58:47 2508572mS CMExtnEvt: v=2 State, new=CMESCompleted old=Proceeding,0,0,Ext421
10:58:47 2508572mS CMCallEvt: 0.1041.0 -1 H323TrunkEP: StateChange: END=X CMCSCompleted->CMCSDelete
10:58:47 2508573mS CMCallEvt: END CALL:13 (f4f4a0ec)
10:58:47 2508574mS CMCallEvt: 0.1041.0 -1 BaseEP: DELETE CMEndpoint f4f3fdd4 TOTAL NOW=1 CALL_LIST=0
10:58:47 2508576mS CMMap: PCG::AddToneGenerator g B1[4] for cp[140]b0r1 append pcp[142]b0r1 (total 1)
10:58:47 2508576mS CMMap: PlatformConnectionAudioSAP::Bind pcp[142]b0r1 to 0.0
10:58:47 2508576mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[142]b0r1 Configure 0.0
10:58:47 2508576mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[142]b0r1 ConnectIndication 0.0
10:58:47 2508576mS CMMap: a=0.0 b=0.0 pcp[140]b0r1 RTPB1
10:58:47 2508576mS H323Evt: SetOperational 13 192.168.49.10:49152 to 1
10:58:48 2509718mS H323Evt: RTP(50r): 192.168.49.10/49152 192.168.49.108/50230 CODEC=Ulaw64K(5) PKTSZ=160 RFC2833=off AGE=3430 SENT=57 (avg size=164) RECV=50 (avg size=160)
10:58:49 2510235mS CMExtnTx: v=421, p1=8000
CMFacility
Line: type=IPLine 250 Call: lid=251 id=2 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
10:58:49 2510235mS CMExtnRx: v=421, p1=0
CMReleaseComp
Line: type=IPLine 250 Call: lid=251 id=1039 in=0
10:58:49 2510235mS CMCallEvt: 251.1039.0 -1 Ext421.0: StateChange: END=X CMCSCompletedTone->CMCSCompleted
10:58:49 2510237mS CMExtnTx: v=421, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=251 id=1039 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
Timed: 25/09/14 10:58
10:58:49 2510237mS CMExtnEvt: v=2 State, new=PortRecoverDelay old=CMESCompleted,0,0,Ext421
10:58:49 2510238mS CMExtnEvt: Ext421: CALL LOST (CMCauseForceClear)
10:58:49 2510238mS CMExtnEvt: Ext421: Extn(421) Calling Party Number(421) Type(CMNTypeInternal)
10:58:49 2510238mS CMExtnEvt: Ext421: CMExtnHandler::SetCurrent( id: 1039->0 )
10:58:49 2510239mS CMCallEvt: 251.1039.0 -1 Ext421.-1: StateChange: END=X CMCSCompleted->CMCSDelete
10:58:49 2510240mS CMTARGET: 251.1039.0 -1 BaseEP: ~CMTargetHandler f4f43b3c ep f4f4b604
10:58:49 2510240mS CMCallEvt: 251.1039.0 -1 BaseEP: DELETE CMEndpoint f4f4b604 TOTAL NOW=0 CALL_LIST=0
10:58:49 2510242mS CMMap: a=0.0 b=0.0 pcp[140]b0r1 RTPB0
10:58:49 2510242mS H323Evt: SetOperational 13 192.168.49.10:49152 to 0
10:58:49 2510242mS H323Evt: RTP(END): 192.168.49.10/49152 192.168.49.108/50230 CODEC=Ulaw64K(5) PKTSZ=160 RFC2833=off AGE=3954 SENT=83 RECV=76 RTdelay=0 jitter=0 loss=0 remotejitter=0 remoteloss=0
10:58:50 2512239mS CMExtnEvt: Ext421: Recover Timer reason=CMTRWrapUp
10:58:50 2512239mS CMExtnEvt: v=2 State, new=Idle old=PortRecoverDelay,0,0,Ext421
10:58:50 2512239mS CMExtnTx: v=421, p1=0
CMVoiceMailStatus
Line: type=IPLine 250 Call: lid=0 id=-1 in=0
Called[Ext421 Msgs=0 Old=0 Sav=0] Type=Default (100) Reason=CMDRdirect Calling[00000000] Type=Default Plan=Default
Display [Ext421 Msgs=0]
Timed: 25/09/14 10:58
Any help as always much appreciated.
0:58:45 2506273mS PRN: 421: Digit Pressed 2
10:58:45 2506274mS CMCallEvt: 0.1039.0 -1 BaseEP: NEW CMEndpoint f4f4b604 TOTAL NOW=1 CALL_LIST=0
10:58:45 2506274mS CMCallEvt: 0.1039.0 -1 Ext421.-1: NEW CMExtnEndpoint f4f4b604, Name=Ext421, Extn=421, Phys Extn=421
10:58:45 2506275mS CMCallEvt: CREATE CALL:13 (f4f4a0ec)
10:58:45 2506275mS CMCallEvt: 0.1040.0 -1 BaseEP: NEW CMEndpoint f5767c6c TOTAL NOW=2 CALL_LIST=0
10:58:45 2506277mS CMExtnEvt: Ext421: CMExtnHandler::SetCurrent( id: 0->1039 )
10:58:45 2506278mS CMExtnRx: v=421, p1=0
CMSetup
Line: type=IPLine 250 Call: lid=251 id=1039 in=0
Called[] Type=Default (100) Reason=CMDRdirect Calling[421] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw
IE CMIEFastStartInfoData (6) 10 item(s)
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=Ext421
10:58:45 2506278mS CMCallEvt: 251.1039.0 13 Ext421.0: StateChange: END=A CMCSIdle->CMCSDialInitiated
10:58:45 2506278mS CMExtnEvt: v=2 State, new=Dialling old=Idle,0,0,Ext421
10:58:45 2506278mS CMTARGET: 251.1039.0 13 Ext421.0: LOOKUP CALL ROUTE: type=100 called_party= sub= calling=421 dir=out complete=0 ses=0
10:58:45 2506279mS CMTARGET: 251.1039.0 13 Ext421.0: ADD TARGET (N): number= type=100 depth=1 nobar=1 setorig=1 ses=0
10:58:45 2506279mS CMCallEvt: 251.1039.0 13 Ext421.0: StateChange: END=A CMCSDialInitiated->CMCSDialling
10:58:45 2506282mS CMExtnTx: v=421, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=251 id=1039 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
IE CMIESecurityData (253) 2 item(s)
Timed: 25/09/14 10:58
10:58:45 2506282mS CMExtnTx: v=421, p1=8000
CMFacility
Line: type=IPLine 250 Call: lid=251 id=2 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
10:58:45 2506282mS CMExtnTx: v=421, p1=0
CMSetupAck
Line: type=IPLine 250 Call: lid=251 id=1039 in=0
Timed: 25/09/14 10:58
10:58:45 2506283mS CMExtnRx: v=421, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=251 id=1039 in=0
Called[2] Type=Default (100) Reason=CMDRdirect Keypad[2]
10:58:45 2506283mS CMTARGET: 251.1039.0 13 Ext421.0: Setting Hard Timer 4000
10:58:45 2506283mS CMTARGET: 251.1039.0 13 Ext421.0: LOOKUP CALL ROUTE: type=100 called_party=2 sub= calling=421 dir=out complete=0 ses=0
10:58:45 2506283mS CMTARGET: 251.1039.0 13 Ext421.0: ADD TARGET (N): number=2 type=100 depth=1 nobar=1 setorig=1 ses=0
10:58:45 2506286mS CD: CALL: 251.1039.0 BState=Idle Cut=0 Music=0.0 Aend="Ext421(421)" (0.0) Bend="" [] (0.0) CalledNum=2 () CallingNum=421 (Ext421) Internal=1 Time=11 AState=Dialling
10:58:45 2506288mS H323Evt: SetOperational 13 192.168.49.10:0 to 0
10:58:45 2506717mS RES: Thu 25/9/2014 10:58:45 FreeMem=54574844 54274012(2) CachedMem=300832 CMMsg=5(6) Buff=5200 1362 1000 7463 5 Links=6639 BTree=14264 CPU=03.95% CPUStats=1/3/16300/25502/25810/0/0 MCR=0 MCW=0
10:58:45 2506717mS RES2: IP 500 V2 9.0.0.0 build 829 Tasks=50 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=62 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=21(TLS=4) TAPI=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
10:58:45 2506717mS RES4: XML MemObjs=56 PoolMem=2097152(1) FreeMem=2081932(1)
10:58:45 2506893mS PRN: 421: Digit Pressed 2
10:58:45 2506893mS CMExtnRx: v=421, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=251 id=1039 in=0
Called[2] Type=Default (100) Reason=CMDRdirect Keypad[2]
10:58:45 2506894mS CMTARGET: 251.1039.0 13 Ext421.0: Setting Hard Timer 4000
10:58:45 2506894mS CMTARGET: 251.1039.0 13 Ext421.0: LOOKUP CALL ROUTE: type=100 called_party=22 sub= calling=421 dir=out complete=0 ses=0
10:58:45 2506894mS CMTARGET: 251.1039.0 13 Ext421.0: ADD TARGET (N): number=22 type=100 depth=1 nobar=1 setorig=1 ses=0
10:58:47 2508533mS PRN: 421: Digit Pressed 1
10:58:47 2508533mS CMExtnRx: v=421, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=251 id=1039 in=0
Called[1] Type=Default (100) Reason=CMDRdirect Keypad[1]
10:58:47 2508534mS CMTARGET: 251.1039.0 13 Ext421.0: Setting Hard Timer 4000
10:58:47 2508534mS CMTARGET: 251.1039.0 13 Ext421.0: LOOKUP CALL ROUTE: type=100 called_party=221 sub= calling=421 dir=out complete=0 ses=0
10:58:47 2508534mS CMTARGET: 251.1039.0 13 Ext421.0: ADD TARGET (N): number=221 type=100 depth=1 nobar=1 setorig=1 ses=0
10:58:47 2508534mS CMTARGET: 251.1039.0 13 Ext421.0: SET USER: J Mendez orig=1
10:58:47 2508534mS CMTARGET: 251.1039.0 13 Ext421.0: ADD USER: J Mendez depth=1 disallow_cw=0 dnd=0 real_call=1 group_call=0 type(CMNTypeDefault) incl(0x0) excpt(0x0), allow_redir(0) remote=c0a8270d simult 0 (0)
10:58:47 2508534mS CMTARGET: 251.1039.0 13 Ext421.0: Direct to Remote Target: J Mendez
10:58:47 2508535mS CMTARGET: 251.1039.0 13 Ext421.0: MakeCallToNetworkedUser J Mendez simult:0 ipad=192.168.39.13 via 192.168.39.13
10:58:47 2508536mS CMCallEvt: 0.1041.0 -1 BaseEP: NEW CMEndpoint f4f3fdd4 TOTAL NOW=3 CALL_LIST=1
10:58:47 2508541mS CMTARGET: MakeCallToNetworkedPBX using line group id: 12 ipaddr=192.168.39.13
10:58:47 2508541mS CMTARGET: 251.1039.0 13 Ext421.0: Targeted OK: J Mendez
10:58:47 2508541mS CMTARGET: 251.1039.0 13 Ext421.0: CancelTimer CMTCDelayedProcessing
10:58:47 2508541mS CMTARGET: 251.1039.0 13 Ext421.0: INITIAL TARGETING SUCCEEDED
10:58:47 2508541mS CMTARGET: 251.1039.0 13 Ext421.0: GetNoAnswerTimer:25
10:58:47 2508542mS CMCallEvt: 251.1039.0 13 Ext421.0: StateChange: END=A CMCSDialling->CMCSDialled
10:58:47 2508542mS CMExtnEvt: v=2 State, new=Proceeding old=Dialling,0,0,Ext421
10:58:47 2508542mS CMExtnTx: v=421, p1=0
CMProceeding
Line: type=IPLine 250 Call: lid=251 id=1039 in=0
Timed: 25/09/14 10:58
10:58:47 2508543mS CMCallEvt: 0.1040.0 13 TargetingEP: StateChange: END=B CMCSIdle->CMCSOffering
10:58:47 2508545mS CMCallEvt: 0.1041.0 13 H323TrunkEP: StateChange: END=T CMCSIdle->CMCSOffering
10:58:47 2508546mS CMLineTx: v=18
CMSetup
Line: type=IPLine 18 Call: lid=0 id=1041 in=0
Called[221] Type=Default (100) Reason=CMDRdirect SndComp Calling[421] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw
IE CMIESupplementaryService (3)
Network Facility Extension
sourceEntity: 0
destinationEntity: 0
Interpretation APDU
discardAnyUnrecognisedInvokePdu
CallingName.Invoke.CodePageUtf8String
invokeId 14637
user 'Ext421' presentation Allowed
IE CMIEFastStartInfoData (6) 6 item(s)
IE CMIECallSignalChannelData (8) unknown
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=Ext421
IE CMIECalledPartyName (224)(Type=CMNameDefault) name=J Mendez
IE CMIECalledPartyKName (225)(Type=CMNameDefault) name=Jac Mendez
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=Ext421
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=421
IE CMIEDeviceDetail (231) LOCALE=enu HW=15 VER=9 class=CMDeviceH323Phone type=88 number=8000 channel=0 features=0x10000420 rx_gain=32 tx_gain=32 ep_callid=1039 ipaddr=192.168.49.10 apps=0 loc=0 em_loc=0 features2=0x0
IE CMIEMohSourceId (247) MOH Source = 255
Timed: 25/09/14 10:58
Locale: enu
10:58:47 2508546mS CD: CALL: 251.1039.0 BState=Idle Cut=1 Music=0.0 Aend="Ext421(421)" (0.0) Bend="J Mendez(221)" [Line 18] (0.0) CalledNum=221 (J Mendez) CallingNum=421 (Ext421) Internal=0 Time=2271 AState=Dialled
10:58:47 2508550mS H323Evt: v=0 stacknum=18 State, new=NullState, old=NullState id=-1
10:58:47 2508552mS H323Evt: v=0 stacknum=18 State, new=Initiated, old=NullState id=1041
10:58:47 2508561mS H323Evt: v=0 stacknum=18 State, new=NullState, old=Initiated id=1041
10:58:47 2508562mS CMLineRx: v=18
CMReleaseComp
Line: type=IPLine 18 Call: lid=0 id=1041 in=0
Cause=17, User busy
10:58:47 2508562mS CMCallEvt: 0.1040.0 13 TargetingEP: RequestEnd 0.1041.0 13 H323TrunkEP
10:58:47 2508562mS CMTARGET: 251.1039.0 13 Ext421.0: CancelTimer CMTCNoAnswerTimeout
10:58:47 2508562mS CMCallEvt: 0.1040.0 -1 BaseEP: DELETE CMEndpoint f5767c6c TOTAL NOW=2 CALL_LIST=1
10:58:47 2508563mS CMCallEvt: 0.1041.0 13 H323TrunkEP: StateChange: END=B CMCSOffering->CMCSCompleted
10:58:47 2508564mS CMExtnTx: v=421, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=251 id=1039 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
Timed: 25/09/14 10:58
10:58:47 2508564mS CMExtnTx: v=421, p1=8000
CMFacility
Line: type=IPLine 250 Call: lid=251 id=2 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
10:58:47 2508567mS CMLOGGING: CALL:2014/09/2510:58,00:00:00,000,421,O,221,221,Ext421,,,0,,""n/a,0
10:58:47 2508567mS CD: CALL: 251.1039.0 BState=Disconnecting Cut=1 Music=0.0 Aend="Ext421(421)" (0.0) Bend="J Mendez(221)" [Line 18] (268.1) CalledNum=221 (J Mendez) CallingNum=421 (Ext421) Internal=0 Time=2292 AState=Dialled
10:58:47 2508567mS CD: CALL: 251.1039.0 Deleted
10:58:47 2508569mS CMExtnEvt: Ext421: CALL LOST (CMCauseBusy)
10:58:47 2508569mS CMExtnEvt: Ext421: Extn(421) Calling Party Number(421) Type(CMNTypeInternal)
10:58:47 2508569mS CMCallEvt: 251.1039.0 -1 Ext421.0: StateChange: END=X CMCSDialled->CMCSCompletedTone
10:58:47 2508571mS CMExtnTx: v=421, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=251 id=1039 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
Timed: 25/09/14 10:58
10:58:47 2508571mS CMExtnTx: v=421, p1=8000
CMFacility
Line: type=IPLine 250 Call: lid=251 id=2 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
10:58:47 2508572mS CMExtnEvt: v=2 State, new=CMESCompleted old=Proceeding,0,0,Ext421
10:58:47 2508572mS CMCallEvt: 0.1041.0 -1 H323TrunkEP: StateChange: END=X CMCSCompleted->CMCSDelete
10:58:47 2508573mS CMCallEvt: END CALL:13 (f4f4a0ec)
10:58:47 2508574mS CMCallEvt: 0.1041.0 -1 BaseEP: DELETE CMEndpoint f4f3fdd4 TOTAL NOW=1 CALL_LIST=0
10:58:47 2508576mS CMMap: PCG::AddToneGenerator g B1[4] for cp[140]b0r1 append pcp[142]b0r1 (total 1)
10:58:47 2508576mS CMMap: PlatformConnectionAudioSAP::Bind pcp[142]b0r1 to 0.0
10:58:47 2508576mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[142]b0r1 Configure 0.0
10:58:47 2508576mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[142]b0r1 ConnectIndication 0.0
10:58:47 2508576mS CMMap: a=0.0 b=0.0 pcp[140]b0r1 RTPB1
10:58:47 2508576mS H323Evt: SetOperational 13 192.168.49.10:49152 to 1
10:58:48 2509718mS H323Evt: RTP(50r): 192.168.49.10/49152 192.168.49.108/50230 CODEC=Ulaw64K(5) PKTSZ=160 RFC2833=off AGE=3430 SENT=57 (avg size=164) RECV=50 (avg size=160)
10:58:49 2510235mS CMExtnTx: v=421, p1=8000
CMFacility
Line: type=IPLine 250 Call: lid=251 id=2 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
10:58:49 2510235mS CMExtnRx: v=421, p1=0
CMReleaseComp
Line: type=IPLine 250 Call: lid=251 id=1039 in=0
10:58:49 2510235mS CMCallEvt: 251.1039.0 -1 Ext421.0: StateChange: END=X CMCSCompletedTone->CMCSCompleted
10:58:49 2510237mS CMExtnTx: v=421, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=251 id=1039 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
Timed: 25/09/14 10:58
10:58:49 2510237mS CMExtnEvt: v=2 State, new=PortRecoverDelay old=CMESCompleted,0,0,Ext421
10:58:49 2510238mS CMExtnEvt: Ext421: CALL LOST (CMCauseForceClear)
10:58:49 2510238mS CMExtnEvt: Ext421: Extn(421) Calling Party Number(421) Type(CMNTypeInternal)
10:58:49 2510238mS CMExtnEvt: Ext421: CMExtnHandler::SetCurrent( id: 1039->0 )
10:58:49 2510239mS CMCallEvt: 251.1039.0 -1 Ext421.-1: StateChange: END=X CMCSCompleted->CMCSDelete
10:58:49 2510240mS CMTARGET: 251.1039.0 -1 BaseEP: ~CMTargetHandler f4f43b3c ep f4f4b604
10:58:49 2510240mS CMCallEvt: 251.1039.0 -1 BaseEP: DELETE CMEndpoint f4f4b604 TOTAL NOW=0 CALL_LIST=0
10:58:49 2510242mS CMMap: a=0.0 b=0.0 pcp[140]b0r1 RTPB0
10:58:49 2510242mS H323Evt: SetOperational 13 192.168.49.10:49152 to 0
10:58:49 2510242mS H323Evt: RTP(END): 192.168.49.10/49152 192.168.49.108/50230 CODEC=Ulaw64K(5) PKTSZ=160 RFC2833=off AGE=3954 SENT=83 RECV=76 RTdelay=0 jitter=0 loss=0 remotejitter=0 remoteloss=0
10:58:50 2512239mS CMExtnEvt: Ext421: Recover Timer reason=CMTRWrapUp
10:58:50 2512239mS CMExtnEvt: v=2 State, new=Idle old=PortRecoverDelay,0,0,Ext421
10:58:50 2512239mS CMExtnTx: v=421, p1=0
CMVoiceMailStatus
Line: type=IPLine 250 Call: lid=0 id=-1 in=0
Called[Ext421 Msgs=0 Old=0 Sav=0] Type=Default (100) Reason=CMDRdirect Calling[00000000] Type=Default Plan=Default
Display [Ext421 Msgs=0]
Timed: 25/09/14 10:58