Hi Guys,
I have an existing full mesh SCN network of 5 systems (mixture of 9 and 8.1) running over MPLS. Two sites have been recently added and appeared to work for about a week. Now we have a problem where the first call to a particular site is successful, but if I hang up and immediately try again I get "unobtainable" (with the correct called name and number displayed).If I leave it for about 30 seconds subsequent calls are okay. This happens between any of the sites across the whole network - if a call is placed between site A and B the first call is okay but the second call fails. Note that and incoming call from B to A is okay while a call from A to B is in progress and the two calls are successful.
Note that 4 voice networking licenses are applied at each site and all sites in the mesh have 4 channels per trunk setup.
The codecs are all set in the following order at each of the sites; G.723,G.729 and G.711 and direct media path is unchecked at all sites. This has been tried with and without shortcodes - just as part of the faultfinding.
Using the status monitor while trying the second call shows that the call is attempted on the first then on the second channel before failing. Monitoring the called site shows that the incoming trunks/channels are not seized and there appears to be no incoming signalling seen by the SysMonitor.
Running a Wireshark Trace on the switch connected directly to the outgoing site IP Office detects no outgoing traffic being presented??
I have been assured that ALG is turned off everywhere and that no firewall blocking is in place for 1718 - 1720 and 50795 etc....
Note from the following trace that I am seeing cause=38 - network failure.
What can be causing this across ALL sites
Failed call from 1382 to 2813 “Old broken fax”
********** Warning: Logging to Screen Started **********
11:24:24 1018015707mS RES: Tue 27/10/2015 11:24:24 FreeMem=41447780 39631404(3) CachedMem=1816376 CMMsg=13(13) Buff=5200 1361 999 7419 5 Links=260280 BTree=10116 CPU=09.70% CPUStats=1/3/219/18302/23230/0/0 MCR=0 MCW=0
11:24:24 1018015707mS RES2: IP 500 V2 9.0.3.0 build 941 Tasks=57 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=226 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=290(TLS=2) TAPI=0 ASC=1 SYS=MNTD OPT=MNTD SDSPD=2034
11:24:24 1018015707mS RES4: XML MemObjs=61 PoolMem=3145765(2) FreeMem=3130302(2)
11:24:24 1018015810mS SCN Ctrl Rx: ParseRemoteBLF from 10.9.3.1 Array Length(91)
11:24:24 1018015942mS CMExtnEvt: OkwdWkRm1: No user activity
11:24:25 1018016311mS SCN Ctrl Tx: PropagateBLF to 10.7.3.1 length=407
11:24:25 1018016312mS SCN Ctrl Tx: PropagateBLF to 10.18.3.1 length=438
11:24:26 1018017437mS CMCallEvt: 0.47569.0 -1 BaseEP: NEW CMEndpoint f412126c TOTAL NOW=5 CALL_LIST=2
11:24:26 1018017437mS CMCallEvt: 0.47569.0 -1 Helpdesk02.-1: NEW CMExtnEndpoint f412126c, Name=Helpdesk02, Extn=1382, Phys Extn=1382
11:24:26 1018017438mS CMCallEvt: CREATE CALL:12012 (f47a8b1c)
11:24:26 1018017438mS CMCallEvt: 0.47570.0 -1 BaseEP: NEW CMEndpoint f451fecc TOTAL NOW=6 CALL_LIST=2
11:24:26 1018017440mS CMExtnEvt: Helpdesk02: CMExtnHandler::SetCurrent( id: 0->47569 )
11:24:26 1018017441mS CMExtnRx: v=1382, p1=0
CMSetup
Line: type=IPLine 250 Call: lid=289 id=47569 in=0
Called[] Type=Default (100) Reason=CMDRdirect Calling[1382] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ALaw
IE CMIEFastStartInfoData (6) 10 item(s)
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=Helpdesk02
IE CMIECallingPartyKName (226)(Type=CMNameDefault) name=Helpdesk 2
11:24:26 1018017441mS CMCallEvt: 289.47569.0 12012 Helpdesk02.0: StateChange: END=A CMCSIdle->CMCSDialInitiated
11:24:26 1018017441mS CMExtnEvt: v=23 State, new=Dialling old=Idle,0,0,Helpdesk02
11:24:26 1018017441mS CMTARGET: 289.47569.0 12012 Helpdesk02.0: LOOKUP CALL ROUTE: type=100 called_party= sub= calling=1382 dir=out complete=0 ses=0
11:24:26 1018017442mS CMTARGET: 289.47569.0 12012 Helpdesk02.0: ADD TARGET (N): number= type=100 depth=1 nobar=1 setorig=1 ses=0
11:24:26 1018017442mS CMCallEvt: 289.47569.0 12012 Helpdesk02.0: StateChange: END=A CMCSDialInitiated->CMCSDialling
11:24:26 1018017446mS CMExtnTx: v=1382, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=289 id=47569 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
IE CMIESecurityData (253) 2 item(s)
Timed: 27/10/15 11:24
11:24:26 1018017446mS CMExtnTx: v=1382, p1=8038
CMFacility
Line: type=IPLine 250 Call: lid=289 id=23 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
11:24:26 1018017446mS CMExtnTx: v=1382, p1=0
CMSetupAck
Line: type=IPLine 250 Call: lid=289 id=47569 in=0
Timed: 27/10/15 11:24
11:24:26 1018017447mS CMExtnTx: v=1382, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=289 id=47569 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
Timed: 27/10/15 11:24
11:24:26 1018017447mS CMExtnTx: v=1382, p1=8038
CMFacility
Line: type=IPLine 250 Call: lid=289 id=23 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
11:24:26 1018017447mS CMExtnTx: v=1382, p1=8038
CMFacility
Line: type=IPLine 250 Call: lid=289 id=23 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
11:24:26 1018017449mS CD: CALL: 289.47569.0 BState=Idle Cut=0 Music=3.0 Aend="Helpdesk02(1382)" (0.0) Bend="" [] (0.0) CalledNum= () CallingNum=1382 (Helpdesk02) Internal=1 Time=11 AState=Dialling
11:24:26 1018017454mS H323Evt: SetOperational 14348 10.1.3.1:0 to 0
11:24:26 1018017454mS CMMap: PCG::AddToneGenerator g D2[2] for cp[612]b0r1 append pcp[613]b0r1 (total 1)
11:24:26 1018017455mS CMMap: PlatformConnectionAudioSAP::Bind pcp[613]b0r1 to 0.0
11:24:26 1018017455mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[613]b0r1 Configure 0.0
11:24:26 1018017455mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[613]b0r1 ConnectIndication 0.0
11:24:26 1018017455mS CMMap: a=0.0 b=0.0 pcp[612]b0r1 RTPD2
11:24:26 1018017455mS H323Evt: SetOperational 14348 10.1.3.1:49154 to 1
11:24:26 1018017676mS SIP Tx: UDP 10.1.3.1:5060 -> 135.196.144.57:5060
OPTIONS sip:ippbx2.hostedipt.co.uk SIP/2.0
Via: SIP/2.0/UDP 10.1.3.1:5060;rport;branch=z9hG4bK567e8f388cfe8ccff492db493fa45916
From: <sip:ippbx2.hostedipt.co.uk>;tag=19249ef1c6a437f1
To: <sip:ippbx2.hostedipt.co.uk>
Call-ID: a06c48c34d320d1d823f1d914f8454b5
CSeq: 1365543539 OPTIONS
Contact: <sip:10.1.3.1:5060;transport=udp>
Max-Forwards: 70
Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,INFO,NOTIFY,UPDATE
Supported: timer
User-Agent: IP Office 9.0.3.0 build 941
Content-Length: 0
11:24:26 1018017703mS SIP Rx: UDP 135.196.144.57:5060 -> 10.1.3.1:5060
SIP/2.0 200 OK
From: <sip:ippbx2.hostedipt.co.uk>;tag=19249ef1c6a437f1
To: <sip:ippbx2.hostedipt.co.uk>;tag=1172755545
Call-ID: a06c48c34d320d1d823f1d914f8454b5
CSeq: 1365543539 OPTIONS
Via: SIP/2.0/UDP 10.1.3.1:5060;branch=z9hG4bK567e8f388cfe8ccff492db493fa45916
Contact: <sip:ippbx2.hostedipt.co.uk:5060;maddr=135.196.144.57>
User-Agent: Nortel SESM 14.0.16.3
Supported: com.nortelnetworks.firewall, p-3rdpartycontrol, nosec, join, x-nortel-sipvc
Content-Length: 0
11:24:26 1018017722mS SIP Tx: UDP 89.197.8.31:5060 -> 88.215.61.201:5060
OPTIONS sip:88.215.61.201 SIP/2.0
Via: SIP/2.0/UDP 89.197.8.31:5060;rport;branch=z9hG4bKe66e08c488e30eab058f8533826434fb
From: <sip:89.197.8.31>;tag=761aef10693de409
To: <sip:88.215.61.201>
Call-ID: bf3c7af1587e79a07baafc21ee155b6a
CSeq: 840003990 OPTIONS
Contact: <sip:89.197.8.31:5060;transport=udp>
Max-Forwards: 70
Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,INFO,REFER,NOTIFY,UPDATE
Supported: timer
User-Agent: IP Office 9.0.3.0 build 941
Content-Length: 0
11:24:26 1018017750mS SIP Rx: UDP 88.215.61.201:5060 -> 89.197.8.31:5060
SIP/2.0 200 OK
Via: SIP/2.0/UDP 89.197.8.31:5060;rport=5060;received=89.197.8.31;branch=z9hG4bKe66e08c488e30eab058f8533826434fb
To: <sip:88.215.61.201>;tag=3654933828-445846
From: <sip:89.197.8.31>;tag=761aef10693de409
Call-ID: bf3c7af1587e79a07baafc21ee155b6a
CSeq: 840003990 OPTIONS
Allow: PUBLISH,MESSAGE,UPDATE,PRACK,SUBSCRIBE,REFER,INFO,NOTIFY,REGISTER,OPTIONS,BYE,INVITE,ACK,CANCEL
Contact: <sip:88.215.61.201:5060>
User-Agent: IP Office 9.0.3.0 build 941
Content-Length: 0
11:24:26 1018017872mS SCN Ctrl Rx: ParseRemoteBLF from 10.9.3.1 Array Length(91)
11:24:26 1018017910mS SCN Ctrl Rx: VPNNetworkedPBX(10.9.3.1)::ReadLII len(24) Unicode(2)
11:24:26 1018017911mS SCN Ctrl Rx: extn(2227) state(0) idle_time(1018017374) mass_update(0)
11:24:26 1018017941mS SCN Ctrl Tx: PropagateBLF to 10.3.3.10 length=270
11:24:26 1018017942mS SCN Ctrl Tx: PropagateBLF to 10.5.3.1 length=270
11:24:26 1018017943mS SCN Ctrl Tx: PropagateBLF to 10.9.3.1 length=270
11:24:26 1018017944mS SCN Ctrl Tx: PropagateBLF to 10.13.3.1 length=270
11:24:26 1018017944mS SCN Ctrl Tx: PropagateBLF to 10.7.3.1 length=407
11:24:26 1018017945mS SCN Ctrl Tx: PropagateBLF to 10.18.3.1 length=438
11:24:27 1018018035mS H323Evt: Recv: RegistrationRequest 10.28.2.26; Endpoints registered: 131; Endpoints in registration: 0
11:24:27 1018018269mS PRN: 1382: Digit Pressed 2
11:24:27 1018018270mS CMExtnRx: v=1382, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=289 id=47569 in=0
Called[2] Type=Default (100) Reason=CMDRdirect Keypad[2]
11:24:27 1018018272mS CMMap: a=0.0 b=0.0 pcp[612]b0r1 RTPD0
11:24:27 1018018272mS H323Evt: SetOperational 14348 10.1.3.1:49154 to 0
11:24:27 1018018388mS SCN Ctrl Rx: ParseRemoteBLF from 10.5.3.1 Array Length(46)
11:24:27 1018018491mS SIP Rx: UDP 10.1.3.50:5060 -> 10.1.3.1:5060
11:24:27 1018018710mS PRN: 1382: Digit Pressed 8
11:24:27 1018018710mS CMExtnRx: v=1382, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=289 id=47569 in=0
Called[8] Type=Default (100) Reason=CMDRdirect Keypad[8]
11:24:27 1018018890mS SCN Ctrl Tx: PropagateBLF to 10.7.3.1 length=407
11:24:27 1018018891mS SCN Ctrl Tx: PropagateBLF to 10.18.3.1 length=438
11:24:28 1018019022mS H323Evt: Recv: RegistrationRequest 10.6.3.33; Endpoints registered: 131; Endpoints in registration: 0
11:24:28 1018019170mS PRN: 1382: Digit Pressed 1
11:24:28 1018019170mS CMExtnRx: v=1382, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=289 id=47569 in=0
Called[1] Type=Default (100) Reason=CMDRdirect Keypad[1]
11:24:28 1018019729mS PRN: 1382: Digit Pressed 3
11:24:28 1018019730mS CMExtnRx: v=1382, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=289 id=47569 in=0
Called[3] Type=Default (100) Reason=CMDRdirect Keypad[3]
11:24:28 1018019730mS CMTARGET: 289.47569.0 12012 Helpdesk02.0: CancelTimer CMTCDelayedProcessing
11:24:28 1018019730mS CMTARGET: 289.47569.0 12012 Helpdesk02.0: LOOKUP CALL ROUTE: type=100 called_party=2813 sub= calling=1382 dir=out complete=0 ses=0
11:24:28 1018019730mS CMTARGET: 289.47569.0 12012 Helpdesk02.0: ADD TARGET (N): number=2813 type=100 depth=1 nobar=1 setorig=1 ses=0
11:24:28 1018019731mS CMTARGET: 289.47569.0 12012 Helpdesk02.0: SET USER: OldFaxBroken orig=1
11:24:28 1018019731mS CMTARGET: 289.47569.0 12012 Helpdesk02.0: ADD USER: OldFaxBroken depth=1 disallow_cw=0 dnd=0 real_call=1 group_call=0 type(CMNTypeDefault) incl(0x0) excpt(0x0), allow_redir(0) remote=0a120301 simult 0 (0)
11:24:28 1018019731mS CMTARGET: 289.47569.0 12012 Helpdesk02.0: Direct to Remote Target: OldFaxBroken
11:24:28 1018019731mS CMTARGET: 289.47569.0 12012 Helpdesk02.0: MakeCallToNetworkedUser OldFaxBroken simult:0 ipad=10.18.3.1 via 10.18.3.1
11:24:28 1018019732mS CMCallEvt: 0.47571.0 -1 BaseEP: NEW CMEndpoint f413b35c TOTAL NOW=7 CALL_LIST=3
11:24:28 1018019734mS CMTARGET: MakeCallToNetworkedPBX using line group id: 106 ipaddr=10.18.3.1
11:24:28 1018019735mS CMTARGET: 289.47569.0 12012 Helpdesk02.0: Targeted OK: OldFaxBroken
11:24:28 1018019735mS CMTARGET: 289.47569.0 12012 Helpdesk02.0: CancelTimer CMTCDialToneTimeout
11:24:28 1018019735mS CMTARGET: 289.47569.0 12012 Helpdesk02.0: INITIAL TARGETING SUCCEEDED
11:24:28 1018019735mS CMTARGET: 289.47569.0 12012 Helpdesk02.0: GetNoAnswerTimer:15
11:24:28 1018019735mS CMCallEvt: 289.47569.0 12012 Helpdesk02.0: StateChange: END=A CMCSDialling->CMCSDialled
11:24:28 1018019735mS CMExtnEvt: v=23 State, new=Proceeding old=Dialling,0,0,Helpdesk02
11:24:28 1018019736mS CMExtnTx: v=1382, p1=0
CMProceeding
Line: type=IPLine 250 Call: lid=289 id=47569 in=0
Timed: 27/10/15 11:24
11:24:28 1018019737mS CMCallEvt: 0.47570.0 12012 TargetingEP: StateChange: END=B CMCSIdle->CMCSOffering
11:24:28 1018019738mS CMCallEvt: 0.47571.0 12012 H323TrunkEP: StateChange: END=T CMCSIdle->CMCSOffering
11:24:28 1018019740mS CMLineTx: v=25
CMSetup
Line: type=IPLine 25 Call: lid=0 id=47571 in=0
Called[2813] Type=Default (100) Reason=CMDRdirect SndComp Calling[1382] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ALaw
IE CMIESupplementaryService (3)
Network Facility Extension
sourceEntity: 0
destinationEntity: 0
Interpretation APDU
discardAnyUnrecognisedInvokePdu
CallingName.Invoke.CodePageUtf8String
invokeId 22939
user 'Helpdesk02' presentation Allowed
IE CMIEFastStartInfoData (6) 2 item(s)
IE CMIECallSignalChannelData (8) unknown
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=Helpdesk02
IE CMIECalledPartyName (224)(Type=CMNameDefault) name=OldFaxBroken
IE CMIECalledPartyKName (225)(Type=CMNameDefault) name=BrokenPort
IE CMIECallingPartyKName (226)(Type=CMNameDefault) name=Helpdesk 2
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=Helpdesk02
IE CMIERespondingPartyKName (229)(Type=CMNameDefault) name=Helpdesk 2
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=1382
IE CMIEDeviceDetail (231) LOCALE=eng HW=15 VER=9 class=CMDeviceH323Phone type=62 number=8038 channel=0 features=0x10000420 rx_gain=32 tx_gain=32 ep_callid=47569 ipaddr=10.1.3.1 apps=0 loc=0 em_loc=0 features2=0x0
IE CMIEMohSourceId (247) MOH Source = 255
Timed: 27/10/15 11:24
Locale: eng
11:24:28 1018019740mS CD: CALL: 289.47569.0 BState=Idle Cut=1 Music=0.0 Aend="Helpdesk02(1382)" (0.0) Bend="OldFaxBroken(2813)" [Line 25] (0.0) CalledNum=2813 (OldFaxBroken) CallingNum=1382 (Helpdesk02) Internal=0 Time=2302 AState=Dialled
11:24:28 1018019741mS H323Evt: v=0 stacknum=25 State, new=NullState, old=NullState id=-1
11:24:28 1018019742mS H323Evt: v=0 stacknum=25 State, new=NullState, old=NullState id=47571
11:24:28 1018019742mS CMLineRx: v=25
CMReleaseComp
Line: type=IPLine 25 Call: lid=0 id=47571 in=0
Cause=38, Network out of order
11:24:28 1018019742mS CMTARGET: 289.47569.0 12012 Helpdesk02.0: Re-target after NetworkOOO - Try: Shortcode(2813)
11:24:28 1018019742mS CMTARGET: 289.47569.0 12012 Helpdesk02.0: ADD TARGET (N): number=2813 type=100 depth=1 nobar=1 setorig=1 ses=0
11:24:28 1018019743mS CMTARGET: 289.47569.0 12012 Helpdesk02.0: SYS SC: 2813 4 3 sc=type=Dial code=281X, num=. callinfop->sending_complete=1 secondary_dialtone=
11:24:28 1018019743mS CMARS: FindActiveARSByGroupID GroupID=106 - Not Found
11:24:28 1018019743mS CMLRQ: FindActiveLRQByGroupID GroupID=106 - Not Found
11:24:28 1018019744mS CMCallEvt: 0.47572.0 -1 BaseEP: NEW CMEndpoint f41612fc TOTAL NOW=8 CALL_LIST=3
11:24:28 1018019745mS CMTARGET: DIAL LINE: 12012 GROUP = 106 SUCCESS = f41612fc
11:24:28 1018019746mS CMTARGET: 289.47569.0 12012 Helpdesk02.0: PrepareTransferTargets Found 1 target
11:24:28 1018019747mS CMCallEvt: 0.47572.0 12012 H323TrunkEP: StateChange: END=T CMCSIdle->CMCSOffering
11:24:28 1018019748mS CMLineTx: v=25
CMSetup
Line: type=IPLine 25 Call: lid=0 id=47572 in=0
Called[2813] Type=Default (100) Reason=CMDRdirect SndComp Calling[1382] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ALaw
IE CMIESupplementaryService (3)
Network Facility Extension
sourceEntity: 0
destinationEntity: 0
Interpretation APDU
discardAnyUnrecognisedInvokePdu
CallingName.Invoke.CodePageUtf8String
invokeId 22940
user 'Helpdesk02' presentation Allowed
IE CMIEFastStartInfoData (6) 2 item(s)
IE CMIECallSignalChannelData (8) unknown
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=Helpdesk02
IE CMIECalledPartyName (224)(Type=CMNameDefault) name=OldFaxBroken
IE CMIECalledPartyKName (225)(Type=CMNameDefault) name=BrokenPort
IE CMIECallingPartyKName (226)(Type=CMNameDefault) name=Helpdesk 2
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=Helpdesk02
IE CMIERespondingPartyKName (229)(Type=CMNameDefault) name=Helpdesk 2
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=1382
IE CMIEDeviceDetail (231) LOCALE=eng HW=15 VER=9 class=CMDeviceH323Phone type=62 number=8038 channel=0 features=0x10000420 rx_gain=32 tx_gain=32 ep_callid=47569 ipaddr=10.1.3.1 apps=0 loc=0 em_loc=0 features2=0x0
IE CMIEMohSourceId (247) MOH Source = 255
Timed: 27/10/15 11:24
Locale: eng
11:24:28 1018019748mS CMLineTx: v=25
CMReleaseComp
Line: type=IPLine 25 Call: lid=0 id=47571 in=0
Cause=16, Normal call clearing
11:24:28 1018019748mS CMCallEvt: 0.47571.0 -1 H323TrunkEP: StateChange: END=X CMCSOffering->CMCSDelete
11:24:28 1018019749mS CMCallEvt: 0.47571.0 -1 BaseEP: DELETE CMEndpoint f413b35c TOTAL NOW=7 CALL_LIST=3
11:24:28 1018019749mS CD: CALL: 289.47569.0 BState=Idle Cut=1 Music=0.0 Aend="Helpdesk02(1382)" (0.0) Bend="OldFaxBroken(2813)" [Line 25] (0.0) CalledNum=2813 (OldFaxBroken) CallingNum=1382 (Helpdesk02) Internal=0 Time=2311 AState=Dialled
11:24:28 1018019752mS H323Evt: v=0 stacknum=25 State, new=NullState, old=NullState id=-1
11:24:28 1018019752mS H323Evt: v=0 stacknum=25 State, new=NullState, old=NullState id=47572
11:24:28 1018019753mS CMLineRx: v=25
CMReleaseComp
Line: type=IPLine 25 Call: lid=0 id=47572 in=0
Cause=38, Network out of order
11:24:28 1018019753mS CMCallEvt: 0.47570.0 12012 TargetingEP: RequestEnd 0.47572.0 12012 H323TrunkEP
11:24:28 1018019753mS CMTARGET: 289.47569.0 12012 Helpdesk02.0: CancelTimer CMTCNoAnswerTimeout
11:24:28 1018019753mS CMCallEvt: 0.47570.0 -1 BaseEP: DELETE CMEndpoint f451fecc TOTAL NOW=6 CALL_LIST=3
11:24:28 1018019754mS CMCallEvt: 0.47572.0 12012 H323TrunkEP: StateChange: END=B CMCSOffering->CMCSCompleted
11:24:28 1018019755mS CMExtnTx: v=1382, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=289 id=47569 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
Timed: 27/10/15 11:24
11:24:28 1018019755mS CMExtnTx: v=1382, p1=8038
CMFacility
Line: type=IPLine 250 Call: lid=289 id=23 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
11:24:28 1018019757mS CMLOGGING: CALL:2015/10/2711:24,00:00:00,000,1382,O,2813,2813,Helpdesk02,,,0,,""n/a,0
11:24:28 1018019757mS CD: CALL: 289.47569.0 BState=Disconnecting Cut=1 Music=0.0 Aend="Helpdesk02(1382)" (0.0) Bend="OldFaxBroken(2813)" [] (275.2) CalledNum=2813 (OldFaxBroken) CallingNum=1382 (Helpdesk02) Internal=0 Time=2319 AState=Dialled
11:24:28 1018019757mS CD: CALL: 289.47569.0 Deleted
11:24:28 1018019759mS CMExtnEvt: Helpdesk02: CALL LOST (CMCauseNetworkOOO)
11:24:28 1018019759mS CMExtnEvt: Helpdesk02: Extn(1382) Calling Party Number(1382) Type(CMNTypeInternal)
11:24:28 1018019760mS CMCallEvt: 289.47569.0 -1 Helpdesk02.0: StateChange: END=X CMCSDialled->CMCSCompletedTone
11:24:28 1018019762mS CMExtnTx: v=1382, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=289 id=47569 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
Timed: 27/10/15 11:24
11:24:28 1018019762mS CMExtnTx: v=1382, p1=8038
CMFacility
Line: type=IPLine 250 Call: lid=289 id=23 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
11:24:28 1018019763mS CMExtnEvt: v=23 State, new=CMESCompleted old=Proceeding,0,0,Helpdesk02
11:24:28 1018019763mS CMCallEvt: 0.47572.0 -1 H323TrunkEP: StateChange: END=X CMCSCompleted->CMCSDelete
11:24:28 1018019763mS CMCallEvt: END CALL:12012 (f47a8b1c)
11:24:28 1018019765mS CMCallEvt: 0.47572.0 -1 BaseEP: DELETE CMEndpoint f41612fc TOTAL NOW=5 CALL_LIST=2
11:24:28 1018019766mS CMMap: PCG::AddToneGenerator g B1[4] for cp[612]b0r1 append pcp[616]b0r1 (total 1)
11:24:28 1018019766mS CMMap: PlatformConnectionAudioSAP::Bind pcp[616]b0r1 to 0.0
11:24:28 1018019767mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[616]b0r1 Configure 0.0
11:24:28 1018019767mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[616]b0r1 ConnectIndication 0.0
11:24:28 1018019767mS CMMap: a=0.0 b=0.0 pcp[612]b0r1 RTPB2
11:24:28 1018019767mS H323Evt: SetOperational 14348 10.1.3.1:49154 to 1
11:24:28 1018019963mS H323Evt: RTP(50t): 10.1.3.1/49154 10.1.3.83/50384 CODEC=Alaw64K(4) PKTSZ=160 RFC2833=off AGE=2509 SENT=50 (avg size=164) RECV=29 (avg size=160)
11:24:29 1018020235mS SCN Ctrl Tx: PropagateBLF to 10.3.3.10 length=270
11:24:29 1018020236mS SCN Ctrl Tx: PropagateBLF to 10.5.3.1 length=270
11:24:29 1018020237mS SCN Ctrl Tx: PropagateBLF to 10.9.3.1 length=270
11:24:29 1018020237mS SCN Ctrl Tx: PropagateBLF to 10.13.3.1 length=270
11:24:29 1018020238mS SCN Ctrl Tx: PropagateBLF to 10.7.3.1 length=407
11:24:29 1018020239mS SCN Ctrl Tx: PropagateBLF to 10.18.3.1 length=438
11:24:28 1018020750mS RES: Tue 27/10/2015 11:24:28 FreeMem=41360604 39565788(2) CachedMem=1794816 CMMsg=13(13) Buff=5200 1361 999 7420 5 Links=260267 BTree=10114 CPU=10.18% CPUStats=12/44/219/17619/23230/0/0 MCR=0 MCW=0
11:24:28 1018020751mS RES2: IP 500 V2 9.0.3.0 build 941 Tasks=57 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=229 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=289(TLS=2) TAPI=0 ASC=1 SYS=MNTD OPT=MNTD SDSPD=2034
11:24:28 1018020751mS RES4: XML MemObjs=61 PoolMem=3145765(2) FreeMem=3130302(2)
11:24:29 1018021025mS H323Evt: Recv: RegistrationRequest 10.1.3.80; Endpoints registered: 131; Endpoints in registration: 0
11:24:29 1018021332mS H323Evt: Shared tcp socket for line 20 disconnected
11:24:29 1018021879mS PRN: Optimizing BTree Lists Completed...Started:1018020952
11:24:30 1018022971mS R2DSP: PRIU DSP 1: is alive
********** Warning: Logging to Screen Stopped **********
Thanks Guys
I have an existing full mesh SCN network of 5 systems (mixture of 9 and 8.1) running over MPLS. Two sites have been recently added and appeared to work for about a week. Now we have a problem where the first call to a particular site is successful, but if I hang up and immediately try again I get "unobtainable" (with the correct called name and number displayed).If I leave it for about 30 seconds subsequent calls are okay. This happens between any of the sites across the whole network - if a call is placed between site A and B the first call is okay but the second call fails. Note that and incoming call from B to A is okay while a call from A to B is in progress and the two calls are successful.
Note that 4 voice networking licenses are applied at each site and all sites in the mesh have 4 channels per trunk setup.
The codecs are all set in the following order at each of the sites; G.723,G.729 and G.711 and direct media path is unchecked at all sites. This has been tried with and without shortcodes - just as part of the faultfinding.
Using the status monitor while trying the second call shows that the call is attempted on the first then on the second channel before failing. Monitoring the called site shows that the incoming trunks/channels are not seized and there appears to be no incoming signalling seen by the SysMonitor.
Running a Wireshark Trace on the switch connected directly to the outgoing site IP Office detects no outgoing traffic being presented??
I have been assured that ALG is turned off everywhere and that no firewall blocking is in place for 1718 - 1720 and 50795 etc....
Note from the following trace that I am seeing cause=38 - network failure.
What can be causing this across ALL sites
Failed call from 1382 to 2813 “Old broken fax”
********** Warning: Logging to Screen Started **********
11:24:24 1018015707mS RES: Tue 27/10/2015 11:24:24 FreeMem=41447780 39631404(3) CachedMem=1816376 CMMsg=13(13) Buff=5200 1361 999 7419 5 Links=260280 BTree=10116 CPU=09.70% CPUStats=1/3/219/18302/23230/0/0 MCR=0 MCW=0
11:24:24 1018015707mS RES2: IP 500 V2 9.0.3.0 build 941 Tasks=57 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=226 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=290(TLS=2) TAPI=0 ASC=1 SYS=MNTD OPT=MNTD SDSPD=2034
11:24:24 1018015707mS RES4: XML MemObjs=61 PoolMem=3145765(2) FreeMem=3130302(2)
11:24:24 1018015810mS SCN Ctrl Rx: ParseRemoteBLF from 10.9.3.1 Array Length(91)
11:24:24 1018015942mS CMExtnEvt: OkwdWkRm1: No user activity
11:24:25 1018016311mS SCN Ctrl Tx: PropagateBLF to 10.7.3.1 length=407
11:24:25 1018016312mS SCN Ctrl Tx: PropagateBLF to 10.18.3.1 length=438
11:24:26 1018017437mS CMCallEvt: 0.47569.0 -1 BaseEP: NEW CMEndpoint f412126c TOTAL NOW=5 CALL_LIST=2
11:24:26 1018017437mS CMCallEvt: 0.47569.0 -1 Helpdesk02.-1: NEW CMExtnEndpoint f412126c, Name=Helpdesk02, Extn=1382, Phys Extn=1382
11:24:26 1018017438mS CMCallEvt: CREATE CALL:12012 (f47a8b1c)
11:24:26 1018017438mS CMCallEvt: 0.47570.0 -1 BaseEP: NEW CMEndpoint f451fecc TOTAL NOW=6 CALL_LIST=2
11:24:26 1018017440mS CMExtnEvt: Helpdesk02: CMExtnHandler::SetCurrent( id: 0->47569 )
11:24:26 1018017441mS CMExtnRx: v=1382, p1=0
CMSetup
Line: type=IPLine 250 Call: lid=289 id=47569 in=0
Called[] Type=Default (100) Reason=CMDRdirect Calling[1382] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ALaw
IE CMIEFastStartInfoData (6) 10 item(s)
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=Helpdesk02
IE CMIECallingPartyKName (226)(Type=CMNameDefault) name=Helpdesk 2
11:24:26 1018017441mS CMCallEvt: 289.47569.0 12012 Helpdesk02.0: StateChange: END=A CMCSIdle->CMCSDialInitiated
11:24:26 1018017441mS CMExtnEvt: v=23 State, new=Dialling old=Idle,0,0,Helpdesk02
11:24:26 1018017441mS CMTARGET: 289.47569.0 12012 Helpdesk02.0: LOOKUP CALL ROUTE: type=100 called_party= sub= calling=1382 dir=out complete=0 ses=0
11:24:26 1018017442mS CMTARGET: 289.47569.0 12012 Helpdesk02.0: ADD TARGET (N): number= type=100 depth=1 nobar=1 setorig=1 ses=0
11:24:26 1018017442mS CMCallEvt: 289.47569.0 12012 Helpdesk02.0: StateChange: END=A CMCSDialInitiated->CMCSDialling
11:24:26 1018017446mS CMExtnTx: v=1382, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=289 id=47569 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
IE CMIESecurityData (253) 2 item(s)
Timed: 27/10/15 11:24
11:24:26 1018017446mS CMExtnTx: v=1382, p1=8038
CMFacility
Line: type=IPLine 250 Call: lid=289 id=23 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
11:24:26 1018017446mS CMExtnTx: v=1382, p1=0
CMSetupAck
Line: type=IPLine 250 Call: lid=289 id=47569 in=0
Timed: 27/10/15 11:24
11:24:26 1018017447mS CMExtnTx: v=1382, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=289 id=47569 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
Timed: 27/10/15 11:24
11:24:26 1018017447mS CMExtnTx: v=1382, p1=8038
CMFacility
Line: type=IPLine 250 Call: lid=289 id=23 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
11:24:26 1018017447mS CMExtnTx: v=1382, p1=8038
CMFacility
Line: type=IPLine 250 Call: lid=289 id=23 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
11:24:26 1018017449mS CD: CALL: 289.47569.0 BState=Idle Cut=0 Music=3.0 Aend="Helpdesk02(1382)" (0.0) Bend="" [] (0.0) CalledNum= () CallingNum=1382 (Helpdesk02) Internal=1 Time=11 AState=Dialling
11:24:26 1018017454mS H323Evt: SetOperational 14348 10.1.3.1:0 to 0
11:24:26 1018017454mS CMMap: PCG::AddToneGenerator g D2[2] for cp[612]b0r1 append pcp[613]b0r1 (total 1)
11:24:26 1018017455mS CMMap: PlatformConnectionAudioSAP::Bind pcp[613]b0r1 to 0.0
11:24:26 1018017455mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[613]b0r1 Configure 0.0
11:24:26 1018017455mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[613]b0r1 ConnectIndication 0.0
11:24:26 1018017455mS CMMap: a=0.0 b=0.0 pcp[612]b0r1 RTPD2
11:24:26 1018017455mS H323Evt: SetOperational 14348 10.1.3.1:49154 to 1
11:24:26 1018017676mS SIP Tx: UDP 10.1.3.1:5060 -> 135.196.144.57:5060
OPTIONS sip:ippbx2.hostedipt.co.uk SIP/2.0
Via: SIP/2.0/UDP 10.1.3.1:5060;rport;branch=z9hG4bK567e8f388cfe8ccff492db493fa45916
From: <sip:ippbx2.hostedipt.co.uk>;tag=19249ef1c6a437f1
To: <sip:ippbx2.hostedipt.co.uk>
Call-ID: a06c48c34d320d1d823f1d914f8454b5
CSeq: 1365543539 OPTIONS
Contact: <sip:10.1.3.1:5060;transport=udp>
Max-Forwards: 70
Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,INFO,NOTIFY,UPDATE
Supported: timer
User-Agent: IP Office 9.0.3.0 build 941
Content-Length: 0
11:24:26 1018017703mS SIP Rx: UDP 135.196.144.57:5060 -> 10.1.3.1:5060
SIP/2.0 200 OK
From: <sip:ippbx2.hostedipt.co.uk>;tag=19249ef1c6a437f1
To: <sip:ippbx2.hostedipt.co.uk>;tag=1172755545
Call-ID: a06c48c34d320d1d823f1d914f8454b5
CSeq: 1365543539 OPTIONS
Via: SIP/2.0/UDP 10.1.3.1:5060;branch=z9hG4bK567e8f388cfe8ccff492db493fa45916
Contact: <sip:ippbx2.hostedipt.co.uk:5060;maddr=135.196.144.57>
User-Agent: Nortel SESM 14.0.16.3
Supported: com.nortelnetworks.firewall, p-3rdpartycontrol, nosec, join, x-nortel-sipvc
Content-Length: 0
11:24:26 1018017722mS SIP Tx: UDP 89.197.8.31:5060 -> 88.215.61.201:5060
OPTIONS sip:88.215.61.201 SIP/2.0
Via: SIP/2.0/UDP 89.197.8.31:5060;rport;branch=z9hG4bKe66e08c488e30eab058f8533826434fb
From: <sip:89.197.8.31>;tag=761aef10693de409
To: <sip:88.215.61.201>
Call-ID: bf3c7af1587e79a07baafc21ee155b6a
CSeq: 840003990 OPTIONS
Contact: <sip:89.197.8.31:5060;transport=udp>
Max-Forwards: 70
Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,INFO,REFER,NOTIFY,UPDATE
Supported: timer
User-Agent: IP Office 9.0.3.0 build 941
Content-Length: 0
11:24:26 1018017750mS SIP Rx: UDP 88.215.61.201:5060 -> 89.197.8.31:5060
SIP/2.0 200 OK
Via: SIP/2.0/UDP 89.197.8.31:5060;rport=5060;received=89.197.8.31;branch=z9hG4bKe66e08c488e30eab058f8533826434fb
To: <sip:88.215.61.201>;tag=3654933828-445846
From: <sip:89.197.8.31>;tag=761aef10693de409
Call-ID: bf3c7af1587e79a07baafc21ee155b6a
CSeq: 840003990 OPTIONS
Allow: PUBLISH,MESSAGE,UPDATE,PRACK,SUBSCRIBE,REFER,INFO,NOTIFY,REGISTER,OPTIONS,BYE,INVITE,ACK,CANCEL
Contact: <sip:88.215.61.201:5060>
User-Agent: IP Office 9.0.3.0 build 941
Content-Length: 0
11:24:26 1018017872mS SCN Ctrl Rx: ParseRemoteBLF from 10.9.3.1 Array Length(91)
11:24:26 1018017910mS SCN Ctrl Rx: VPNNetworkedPBX(10.9.3.1)::ReadLII len(24) Unicode(2)
11:24:26 1018017911mS SCN Ctrl Rx: extn(2227) state(0) idle_time(1018017374) mass_update(0)
11:24:26 1018017941mS SCN Ctrl Tx: PropagateBLF to 10.3.3.10 length=270
11:24:26 1018017942mS SCN Ctrl Tx: PropagateBLF to 10.5.3.1 length=270
11:24:26 1018017943mS SCN Ctrl Tx: PropagateBLF to 10.9.3.1 length=270
11:24:26 1018017944mS SCN Ctrl Tx: PropagateBLF to 10.13.3.1 length=270
11:24:26 1018017944mS SCN Ctrl Tx: PropagateBLF to 10.7.3.1 length=407
11:24:26 1018017945mS SCN Ctrl Tx: PropagateBLF to 10.18.3.1 length=438
11:24:27 1018018035mS H323Evt: Recv: RegistrationRequest 10.28.2.26; Endpoints registered: 131; Endpoints in registration: 0
11:24:27 1018018269mS PRN: 1382: Digit Pressed 2
11:24:27 1018018270mS CMExtnRx: v=1382, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=289 id=47569 in=0
Called[2] Type=Default (100) Reason=CMDRdirect Keypad[2]
11:24:27 1018018272mS CMMap: a=0.0 b=0.0 pcp[612]b0r1 RTPD0
11:24:27 1018018272mS H323Evt: SetOperational 14348 10.1.3.1:49154 to 0
11:24:27 1018018388mS SCN Ctrl Rx: ParseRemoteBLF from 10.5.3.1 Array Length(46)
11:24:27 1018018491mS SIP Rx: UDP 10.1.3.50:5060 -> 10.1.3.1:5060
11:24:27 1018018710mS PRN: 1382: Digit Pressed 8
11:24:27 1018018710mS CMExtnRx: v=1382, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=289 id=47569 in=0
Called[8] Type=Default (100) Reason=CMDRdirect Keypad[8]
11:24:27 1018018890mS SCN Ctrl Tx: PropagateBLF to 10.7.3.1 length=407
11:24:27 1018018891mS SCN Ctrl Tx: PropagateBLF to 10.18.3.1 length=438
11:24:28 1018019022mS H323Evt: Recv: RegistrationRequest 10.6.3.33; Endpoints registered: 131; Endpoints in registration: 0
11:24:28 1018019170mS PRN: 1382: Digit Pressed 1
11:24:28 1018019170mS CMExtnRx: v=1382, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=289 id=47569 in=0
Called[1] Type=Default (100) Reason=CMDRdirect Keypad[1]
11:24:28 1018019729mS PRN: 1382: Digit Pressed 3
11:24:28 1018019730mS CMExtnRx: v=1382, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=289 id=47569 in=0
Called[3] Type=Default (100) Reason=CMDRdirect Keypad[3]
11:24:28 1018019730mS CMTARGET: 289.47569.0 12012 Helpdesk02.0: CancelTimer CMTCDelayedProcessing
11:24:28 1018019730mS CMTARGET: 289.47569.0 12012 Helpdesk02.0: LOOKUP CALL ROUTE: type=100 called_party=2813 sub= calling=1382 dir=out complete=0 ses=0
11:24:28 1018019730mS CMTARGET: 289.47569.0 12012 Helpdesk02.0: ADD TARGET (N): number=2813 type=100 depth=1 nobar=1 setorig=1 ses=0
11:24:28 1018019731mS CMTARGET: 289.47569.0 12012 Helpdesk02.0: SET USER: OldFaxBroken orig=1
11:24:28 1018019731mS CMTARGET: 289.47569.0 12012 Helpdesk02.0: ADD USER: OldFaxBroken depth=1 disallow_cw=0 dnd=0 real_call=1 group_call=0 type(CMNTypeDefault) incl(0x0) excpt(0x0), allow_redir(0) remote=0a120301 simult 0 (0)
11:24:28 1018019731mS CMTARGET: 289.47569.0 12012 Helpdesk02.0: Direct to Remote Target: OldFaxBroken
11:24:28 1018019731mS CMTARGET: 289.47569.0 12012 Helpdesk02.0: MakeCallToNetworkedUser OldFaxBroken simult:0 ipad=10.18.3.1 via 10.18.3.1
11:24:28 1018019732mS CMCallEvt: 0.47571.0 -1 BaseEP: NEW CMEndpoint f413b35c TOTAL NOW=7 CALL_LIST=3
11:24:28 1018019734mS CMTARGET: MakeCallToNetworkedPBX using line group id: 106 ipaddr=10.18.3.1
11:24:28 1018019735mS CMTARGET: 289.47569.0 12012 Helpdesk02.0: Targeted OK: OldFaxBroken
11:24:28 1018019735mS CMTARGET: 289.47569.0 12012 Helpdesk02.0: CancelTimer CMTCDialToneTimeout
11:24:28 1018019735mS CMTARGET: 289.47569.0 12012 Helpdesk02.0: INITIAL TARGETING SUCCEEDED
11:24:28 1018019735mS CMTARGET: 289.47569.0 12012 Helpdesk02.0: GetNoAnswerTimer:15
11:24:28 1018019735mS CMCallEvt: 289.47569.0 12012 Helpdesk02.0: StateChange: END=A CMCSDialling->CMCSDialled
11:24:28 1018019735mS CMExtnEvt: v=23 State, new=Proceeding old=Dialling,0,0,Helpdesk02
11:24:28 1018019736mS CMExtnTx: v=1382, p1=0
CMProceeding
Line: type=IPLine 250 Call: lid=289 id=47569 in=0
Timed: 27/10/15 11:24
11:24:28 1018019737mS CMCallEvt: 0.47570.0 12012 TargetingEP: StateChange: END=B CMCSIdle->CMCSOffering
11:24:28 1018019738mS CMCallEvt: 0.47571.0 12012 H323TrunkEP: StateChange: END=T CMCSIdle->CMCSOffering
11:24:28 1018019740mS CMLineTx: v=25
CMSetup
Line: type=IPLine 25 Call: lid=0 id=47571 in=0
Called[2813] Type=Default (100) Reason=CMDRdirect SndComp Calling[1382] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ALaw
IE CMIESupplementaryService (3)
Network Facility Extension
sourceEntity: 0
destinationEntity: 0
Interpretation APDU
discardAnyUnrecognisedInvokePdu
CallingName.Invoke.CodePageUtf8String
invokeId 22939
user 'Helpdesk02' presentation Allowed
IE CMIEFastStartInfoData (6) 2 item(s)
IE CMIECallSignalChannelData (8) unknown
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=Helpdesk02
IE CMIECalledPartyName (224)(Type=CMNameDefault) name=OldFaxBroken
IE CMIECalledPartyKName (225)(Type=CMNameDefault) name=BrokenPort
IE CMIECallingPartyKName (226)(Type=CMNameDefault) name=Helpdesk 2
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=Helpdesk02
IE CMIERespondingPartyKName (229)(Type=CMNameDefault) name=Helpdesk 2
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=1382
IE CMIEDeviceDetail (231) LOCALE=eng HW=15 VER=9 class=CMDeviceH323Phone type=62 number=8038 channel=0 features=0x10000420 rx_gain=32 tx_gain=32 ep_callid=47569 ipaddr=10.1.3.1 apps=0 loc=0 em_loc=0 features2=0x0
IE CMIEMohSourceId (247) MOH Source = 255
Timed: 27/10/15 11:24
Locale: eng
11:24:28 1018019740mS CD: CALL: 289.47569.0 BState=Idle Cut=1 Music=0.0 Aend="Helpdesk02(1382)" (0.0) Bend="OldFaxBroken(2813)" [Line 25] (0.0) CalledNum=2813 (OldFaxBroken) CallingNum=1382 (Helpdesk02) Internal=0 Time=2302 AState=Dialled
11:24:28 1018019741mS H323Evt: v=0 stacknum=25 State, new=NullState, old=NullState id=-1
11:24:28 1018019742mS H323Evt: v=0 stacknum=25 State, new=NullState, old=NullState id=47571
11:24:28 1018019742mS CMLineRx: v=25
CMReleaseComp
Line: type=IPLine 25 Call: lid=0 id=47571 in=0
Cause=38, Network out of order
11:24:28 1018019742mS CMTARGET: 289.47569.0 12012 Helpdesk02.0: Re-target after NetworkOOO - Try: Shortcode(2813)
11:24:28 1018019742mS CMTARGET: 289.47569.0 12012 Helpdesk02.0: ADD TARGET (N): number=2813 type=100 depth=1 nobar=1 setorig=1 ses=0
11:24:28 1018019743mS CMTARGET: 289.47569.0 12012 Helpdesk02.0: SYS SC: 2813 4 3 sc=type=Dial code=281X, num=. callinfop->sending_complete=1 secondary_dialtone=
11:24:28 1018019743mS CMARS: FindActiveARSByGroupID GroupID=106 - Not Found
11:24:28 1018019743mS CMLRQ: FindActiveLRQByGroupID GroupID=106 - Not Found
11:24:28 1018019744mS CMCallEvt: 0.47572.0 -1 BaseEP: NEW CMEndpoint f41612fc TOTAL NOW=8 CALL_LIST=3
11:24:28 1018019745mS CMTARGET: DIAL LINE: 12012 GROUP = 106 SUCCESS = f41612fc
11:24:28 1018019746mS CMTARGET: 289.47569.0 12012 Helpdesk02.0: PrepareTransferTargets Found 1 target
11:24:28 1018019747mS CMCallEvt: 0.47572.0 12012 H323TrunkEP: StateChange: END=T CMCSIdle->CMCSOffering
11:24:28 1018019748mS CMLineTx: v=25
CMSetup
Line: type=IPLine 25 Call: lid=0 id=47572 in=0
Called[2813] Type=Default (100) Reason=CMDRdirect SndComp Calling[1382] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ALaw
IE CMIESupplementaryService (3)
Network Facility Extension
sourceEntity: 0
destinationEntity: 0
Interpretation APDU
discardAnyUnrecognisedInvokePdu
CallingName.Invoke.CodePageUtf8String
invokeId 22940
user 'Helpdesk02' presentation Allowed
IE CMIEFastStartInfoData (6) 2 item(s)
IE CMIECallSignalChannelData (8) unknown
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=Helpdesk02
IE CMIECalledPartyName (224)(Type=CMNameDefault) name=OldFaxBroken
IE CMIECalledPartyKName (225)(Type=CMNameDefault) name=BrokenPort
IE CMIECallingPartyKName (226)(Type=CMNameDefault) name=Helpdesk 2
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=Helpdesk02
IE CMIERespondingPartyKName (229)(Type=CMNameDefault) name=Helpdesk 2
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=1382
IE CMIEDeviceDetail (231) LOCALE=eng HW=15 VER=9 class=CMDeviceH323Phone type=62 number=8038 channel=0 features=0x10000420 rx_gain=32 tx_gain=32 ep_callid=47569 ipaddr=10.1.3.1 apps=0 loc=0 em_loc=0 features2=0x0
IE CMIEMohSourceId (247) MOH Source = 255
Timed: 27/10/15 11:24
Locale: eng
11:24:28 1018019748mS CMLineTx: v=25
CMReleaseComp
Line: type=IPLine 25 Call: lid=0 id=47571 in=0
Cause=16, Normal call clearing
11:24:28 1018019748mS CMCallEvt: 0.47571.0 -1 H323TrunkEP: StateChange: END=X CMCSOffering->CMCSDelete
11:24:28 1018019749mS CMCallEvt: 0.47571.0 -1 BaseEP: DELETE CMEndpoint f413b35c TOTAL NOW=7 CALL_LIST=3
11:24:28 1018019749mS CD: CALL: 289.47569.0 BState=Idle Cut=1 Music=0.0 Aend="Helpdesk02(1382)" (0.0) Bend="OldFaxBroken(2813)" [Line 25] (0.0) CalledNum=2813 (OldFaxBroken) CallingNum=1382 (Helpdesk02) Internal=0 Time=2311 AState=Dialled
11:24:28 1018019752mS H323Evt: v=0 stacknum=25 State, new=NullState, old=NullState id=-1
11:24:28 1018019752mS H323Evt: v=0 stacknum=25 State, new=NullState, old=NullState id=47572
11:24:28 1018019753mS CMLineRx: v=25
CMReleaseComp
Line: type=IPLine 25 Call: lid=0 id=47572 in=0
Cause=38, Network out of order
11:24:28 1018019753mS CMCallEvt: 0.47570.0 12012 TargetingEP: RequestEnd 0.47572.0 12012 H323TrunkEP
11:24:28 1018019753mS CMTARGET: 289.47569.0 12012 Helpdesk02.0: CancelTimer CMTCNoAnswerTimeout
11:24:28 1018019753mS CMCallEvt: 0.47570.0 -1 BaseEP: DELETE CMEndpoint f451fecc TOTAL NOW=6 CALL_LIST=3
11:24:28 1018019754mS CMCallEvt: 0.47572.0 12012 H323TrunkEP: StateChange: END=B CMCSOffering->CMCSCompleted
11:24:28 1018019755mS CMExtnTx: v=1382, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=289 id=47569 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
Timed: 27/10/15 11:24
11:24:28 1018019755mS CMExtnTx: v=1382, p1=8038
CMFacility
Line: type=IPLine 250 Call: lid=289 id=23 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
11:24:28 1018019757mS CMLOGGING: CALL:2015/10/2711:24,00:00:00,000,1382,O,2813,2813,Helpdesk02,,,0,,""n/a,0
11:24:28 1018019757mS CD: CALL: 289.47569.0 BState=Disconnecting Cut=1 Music=0.0 Aend="Helpdesk02(1382)" (0.0) Bend="OldFaxBroken(2813)" [] (275.2) CalledNum=2813 (OldFaxBroken) CallingNum=1382 (Helpdesk02) Internal=0 Time=2319 AState=Dialled
11:24:28 1018019757mS CD: CALL: 289.47569.0 Deleted
11:24:28 1018019759mS CMExtnEvt: Helpdesk02: CALL LOST (CMCauseNetworkOOO)
11:24:28 1018019759mS CMExtnEvt: Helpdesk02: Extn(1382) Calling Party Number(1382) Type(CMNTypeInternal)
11:24:28 1018019760mS CMCallEvt: 289.47569.0 -1 Helpdesk02.0: StateChange: END=X CMCSDialled->CMCSCompletedTone
11:24:28 1018019762mS CMExtnTx: v=1382, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=289 id=47569 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
Timed: 27/10/15 11:24
11:24:28 1018019762mS CMExtnTx: v=1382, p1=8038
CMFacility
Line: type=IPLine 250 Call: lid=289 id=23 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
11:24:28 1018019763mS CMExtnEvt: v=23 State, new=CMESCompleted old=Proceeding,0,0,Helpdesk02
11:24:28 1018019763mS CMCallEvt: 0.47572.0 -1 H323TrunkEP: StateChange: END=X CMCSCompleted->CMCSDelete
11:24:28 1018019763mS CMCallEvt: END CALL:12012 (f47a8b1c)
11:24:28 1018019765mS CMCallEvt: 0.47572.0 -1 BaseEP: DELETE CMEndpoint f41612fc TOTAL NOW=5 CALL_LIST=2
11:24:28 1018019766mS CMMap: PCG::AddToneGenerator g B1[4] for cp[612]b0r1 append pcp[616]b0r1 (total 1)
11:24:28 1018019766mS CMMap: PlatformConnectionAudioSAP::Bind pcp[616]b0r1 to 0.0
11:24:28 1018019767mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[616]b0r1 Configure 0.0
11:24:28 1018019767mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[616]b0r1 ConnectIndication 0.0
11:24:28 1018019767mS CMMap: a=0.0 b=0.0 pcp[612]b0r1 RTPB2
11:24:28 1018019767mS H323Evt: SetOperational 14348 10.1.3.1:49154 to 1
11:24:28 1018019963mS H323Evt: RTP(50t): 10.1.3.1/49154 10.1.3.83/50384 CODEC=Alaw64K(4) PKTSZ=160 RFC2833=off AGE=2509 SENT=50 (avg size=164) RECV=29 (avg size=160)
11:24:29 1018020235mS SCN Ctrl Tx: PropagateBLF to 10.3.3.10 length=270
11:24:29 1018020236mS SCN Ctrl Tx: PropagateBLF to 10.5.3.1 length=270
11:24:29 1018020237mS SCN Ctrl Tx: PropagateBLF to 10.9.3.1 length=270
11:24:29 1018020237mS SCN Ctrl Tx: PropagateBLF to 10.13.3.1 length=270
11:24:29 1018020238mS SCN Ctrl Tx: PropagateBLF to 10.7.3.1 length=407
11:24:29 1018020239mS SCN Ctrl Tx: PropagateBLF to 10.18.3.1 length=438
11:24:28 1018020750mS RES: Tue 27/10/2015 11:24:28 FreeMem=41360604 39565788(2) CachedMem=1794816 CMMsg=13(13) Buff=5200 1361 999 7420 5 Links=260267 BTree=10114 CPU=10.18% CPUStats=12/44/219/17619/23230/0/0 MCR=0 MCW=0
11:24:28 1018020751mS RES2: IP 500 V2 9.0.3.0 build 941 Tasks=57 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=229 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=289(TLS=2) TAPI=0 ASC=1 SYS=MNTD OPT=MNTD SDSPD=2034
11:24:28 1018020751mS RES4: XML MemObjs=61 PoolMem=3145765(2) FreeMem=3130302(2)
11:24:29 1018021025mS H323Evt: Recv: RegistrationRequest 10.1.3.80; Endpoints registered: 131; Endpoints in registration: 0
11:24:29 1018021332mS H323Evt: Shared tcp socket for line 20 disconnected
11:24:29 1018021879mS PRN: Optimizing BTree Lists Completed...Started:1018020952
11:24:30 1018022971mS R2DSP: PRIU DSP 1: is alive
********** Warning: Logging to Screen Stopped **********
Thanks Guys
