gmacdonald78
Programmer
Hi All,
We have a site here that dials intermittently over there SIP trunk, some calls go out some fail over to ISDN Im banging my head against a brick wall now with this one. We didn't set up the SIP trunks and have now access to the router. We have checked and double checked the IPO and other than 1 thing that I spotted cant see any issues. Im going to try changing this one thing tonight [i](transport tab within sip trunk, network configuration "Use network topology info" currently set to "none" going to give lan 2 a try tonight)[/i]
Heres a trace of the last call that failed over SIP
10:12:33 1639925mS PRN: Monitor Status IP 500 V2 9.0.3.0 build 941
10:12:33 1639925mS PRN: LAW=A PRI=1, BRI=0, ALOG=4, VCOMP=42, MDM=0, WAN=0, MODU=2 LANM=0 CkSRC=1 VMAIL=1(VER=3 TYP=1) 1-X=1 CALLS=3(TOT=35)
10:12:34 1640316mS PRN: 3049: Digit Pressed 9
10:12:34 1640317mS CMCallEvt: 0.1126.0 -1 BaseEP: NEW CMEndpoint f43fb02c TOTAL NOW=7 CALL_LIST=3
10:12:34 1640317mS CMCallEvt: 0.1126.0 -1 R Russell Smith.-1: NEW CMExtnEndpoint f43fb02c, Name=R Russell Smith, Extn=3049, Phys Extn=3049
10:12:34 1640318mS CMCallEvt: CREATE CALL:36 (f437ac04)
10:12:34 1640319mS CMCallEvt: 0.1127.0 -1 BaseEP: NEW CMEndpoint f44847c4 TOTAL NOW=8 CALL_LIST=3
10:12:34 1640322mS CMExtnEvt: R Russell Smith: CMExtnHandler::SetCurrent( id: 0->1126 )
10:12:34 1640323mS CMExtnRx: v=3049, p1=0
CMSetup
Line: type=IPLine 250 Call: lid=300 id=1126 in=0
Called[] Type=Default (100) Reason=CMDRdirect Calling[3049] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ALaw
IE CMIEFastStartInfoData (6) 12 item(s)
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=R Russell Smith
IE CMIECallingPartyKName (226)(Type=CMNameDefault) name=Rob Russell Smith
10:12:34 1640324mS CMCallEvt: 300.1126.0 36 R Russell Smith.0: StateChange: END=A CMCSIdle->CMCSDialInitiated
10:12:34 1640324mS CMExtnEvt: v=41 State, new=Dialling old=Idle,0,0,R Russell Smith
10:12:34 1640325mS CMTARGET: 300.1126.0 36 R Russell Smith.0: LOOKUP CALL ROUTE: type=100 called_party= sub= calling=3049 dir=out complete=0 ses=0
10:12:34 1640325mS CMTARGET: 300.1126.0 36 R Russell Smith.0: ADD TARGET (N): number= type=100 depth=1 nobar=1 setorig=1 ses=0
10:12:34 1640326mS CMCallEvt: 300.1126.0 36 R Russell Smith.0: StateChange: END=A CMCSDialInitiated->CMCSDialling
10:12:34 1640330mS CMExtnTx: v=3049, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=300 id=1126 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
IE CMIESecurityData (253) 2 item(s)
CMSecurityElement RX_ONLY {
CMSRTPCryptoCapability none
Codecs list (size 4)
}
CMSecurityElement TX_ONLY {
CMSRTPCryptoCapability none
Codecs list (size 4)
}
Timed: 22/06/16 10:12
10:12:34 1640331mS CMExtnTx: v=3049, p1=8049
CMFacility
Line: type=IPLine 250 Call: lid=300 id=41 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
10:12:34 1640332mS CMExtnTx: v=3049, p1=0
CMSetupAck
Line: type=IPLine 250 Call: lid=300 id=1126 in=0
Timed: 22/06/16 10:12
10:12:34 1640332mS CMExtnTx: v=3049, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=300 id=1126 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
Timed: 22/06/16 10:12
10:12:34 1640333mS CMExtnTx: v=3049, p1=8049
CMFacility
Line: type=IPLine 250 Call: lid=300 id=41 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
10:12:34 1640333mS CMExtnTx: v=3049, p1=8049
CMFacility
Line: type=IPLine 250 Call: lid=300 id=41 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
10:12:34 1640334mS CMExtnRx: v=3049, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=300 id=1126 in=0
Called[9] Type=Default (100) Reason=CMDRdirect Keypad[9]
10:12:34 1640339mS CD: CALL: 300.1126.0 BState=Idle Cut=0 Music=0.0 Aend="R Russell Smith(3049)" (0.0) Bend="" [] (0.0) CalledNum=9 () CallingNum=3049 (R Russell Smith) Internal=1 Time=21 AState=Dialling
10:12:34 1640343mS H323Evt: Recv: RegistrationRequest 10.0.2.155; Endpoints registered: 89; Endpoints in registration: 0
10:12:34 1640344mS H323Evt: SetOperational 48 10.0.2.200:0 to 0
10:12:34 1640851mS PRN: 3049: Digit Pressed 0
10:12:34 1640851mS CMExtnRx: v=3049, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=300 id=1126 in=0
Called[0] Type=Default (100) Reason=CMDRdirect Keypad[0]
10:12:35 1641310mS H323Evt: Recv: RegistrationRequest 10.0.2.146; Endpoints registered: 89; Endpoints in registration: 0
10:12:35 1641323mS H323Evt: Recv: RegistrationRequest 10.0.2.157; Endpoints registered: 89; Endpoints in registration: 0
10:12:35 1641499mS PRN: 3049: Digit Pressed 1
10:12:35 1641500mS CMExtnRx: v=3049, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=300 id=1126 in=0
Called[1] Type=Default (100) Reason=CMDRdirect Keypad[1]
10:12:35 1641920mS PRN: 3049: Digit Pressed 2
10:12:35 1641920mS CMExtnRx: v=3049, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=300 id=1126 in=0
Called[2] Type=Default (100) Reason=CMDRdirect Keypad[2]
10:12:35 1641921mS CMTARGET: 300.1126.0 36 R Russell Smith.0: CancelTimer CMTCDelayedProcessing
10:12:35 1641922mS CMTARGET: 300.1126.0 36 R Russell Smith.0: LOOKUP CALL ROUTE: type=100 called_party=9012 sub= calling=3049 dir=out complete=0 ses=0
10:12:35 1641922mS CMTARGET: 300.1126.0 36 R Russell Smith.0: ADD TARGET (N): number=9012 type=100 depth=1 nobar=1 setorig=1 ses=0
10:12:35 1641923mS CMTARGET: 300.1126.0 36 R Russell Smith.0: SYS SC: 9012 2 012 sc=type=Dial code=9N, num=N callinfop->sending_complete=0 secondary_dialtone=
10:12:35 1641924mS CMARS: FindActiveARSByGroupID GroupID=51 - Found
10:12:35 1641924mS CMARS: MakeCallTarget - Called Number: 012
10:12:35 1641924mS CMCallEvt: 0.1128.0 -1 BaseEP: NEW CMEndpoint f4337a94 TOTAL NOW=9 CALL_LIST=4
10:12:35 1641925mS CMTARGET: 300.1126.0 36 R Russell Smith.0: CancelTimer CMTCDialToneTimeout
10:12:35 1641926mS CMTARGET: 300.1126.0 36 R Russell Smith.0: INITIAL TARGETING SUCCEEDED
10:12:35 1641926mS CMTARGET: 300.1126.0 36 R Russell Smith.0: GetNoAnswerTimer:15
10:12:35 1641926mS CMCallEvt: 0.1127.0 36 TargetingEP: StateChange: END=B CMCSIdle->CMCSOffering
10:12:35 1641928mS CMCallEvt: 0.1128.0 36 ARS for SIPPrimary: StateChange: END=T CMCSIdle->CMCSOffering
10:12:35 1641928mS CMCallEvt: 0.1127.0 36 TargetingEP: RequestEnd 0.1128.0 36 ARS for SIPPrimary
10:12:35 1641929mS CMTARGET: 300.1126.0 36 R Russell Smith.0: CancelTimer CMTCNoAnswerTimeout
10:12:35 1641930mS CMCallEvt: 0.1128.0 36 ARS for SIPPrimary: StateChange: END=B CMCSOffering->CMCSOverlapRecv
10:12:35 1641930mS CMARS: FORM: SIPPrimary - Received Number: 012
10:12:35 1641931mS CMARS: CMARSTargetingPending
10:12:35 1641931mS CMCallEvt: 0.1127.0 -1 TargetingEP: StateChange: END=X CMCSOffering->CMCSDelete
10:12:35 1641931mS CMCallEvt: 0.1127.0 -1 BaseEP: DELETE CMEndpoint f44847c4 TOTAL NOW=8 CALL_LIST=4
10:12:35 1641932mS CD: CALL: 300.1126.0 BState=Idle Cut=2 Music=0.0 Aend="R Russell Smith(3049)" (0.0) Bend="" [] (0.0) CalledNum=9012 () CallingNum=3049 (R Russell Smith) Internal=1 Time=1614 AState=Dialling
10:12:36 1642106mS PRN: 3049: Digit Pressed 5
10:12:36 1642107mS CMExtnRx: v=3049, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=300 id=1126 in=0
Called[5] Type=Default (100) Reason=CMDRdirect Keypad[5]
10:12:36 1642108mS CMARS: FORM: SIPPrimary - Received Number: 0125
10:12:36 1642108mS CMARS: CMARSTargetingPending
10:12:36 1642298mS PRN: 3049: Digit Pressed 2
10:12:36 1642298mS CMExtnRx: v=3049, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=300 id=1126 in=0
Called[2] Type=Default (100) Reason=CMDRdirect Keypad[2]
10:12:36 1642299mS CMARS: FORM: SIPPrimary - Received Number: 01252
10:12:36 1642299mS CMARS: CMARSTargetingPending
10:12:36 1642324mS H323Evt: Recv: RegistrationRequest 10.0.2.159; Endpoints registered: 89; Endpoints in registration: 0
10:12:36 1642467mS H323Evt: Recv: RegistrationRequest 10.0.2.180; Endpoints registered: 89; Endpoints in registration: 0
10:12:36 1642522mS PRN: 3049: Digit Pressed 9
10:12:36 1642523mS CMExtnRx: v=3049, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=300 id=1126 in=0
Called[9] Type=Default (100) Reason=CMDRdirect Keypad[9]
10:12:36 1642524mS CMARS: FORM: SIPPrimary - Received Number: 012529
10:12:36 1642524mS CMARS: CMARSTargetingPending
10:12:36 1642732mS H323Evt: Recv: RegistrationRequest 10.0.2.195; Endpoints registered: 89; Endpoints in registration: 0
10:12:36 1642818mS PRN: 3049: Digit Pressed 0
10:12:36 1642819mS CMExtnRx: v=3049, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=300 id=1126 in=0
Called[0] Type=Default (100) Reason=CMDRdirect Keypad[0]
10:12:36 1642820mS CMARS: FORM: SIPPrimary - Received Number: 0125290
10:12:36 1642820mS CMARS: CMARSTargetingPending
10:12:37 1643036mS PRN: 3049: Digit Pressed 4
10:12:37 1643037mS CMExtnRx: v=3049, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=300 id=1126 in=0
Called[4] Type=Default (100) Reason=CMDRdirect Keypad[4]
10:12:37 1643037mS CMARS: FORM: SIPPrimary - Received Number: 01252904
10:12:37 1643038mS CMARS: CMARSTargetingPending
10:12:37 1643246mS SIP Tx: UDP 192.168.42.1:5060 -> 88.215.63.11:5060
OPTIONS sip:88.215.63.11 SIP/2.0
Via: SIP/2.0/UDP 192.168.42.1:5060;rport;branch=z9hG4bK76e11bce9efa3445749fa5442eb02b64
From: <sip:192.168.42.1>;tag=0366e2a395ba4514
To: <sip:88.215.63.11>
Call-ID: 2683f22db1d4fe423ef5cf3af121646d
CSeq: 1658998434 OPTIONS
Contact: <sip:192.168.42.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
10:12:37 1643251mS PRN: 3049: Digit Pressed 8
10:12:37 1643251mS CMExtnRx: v=3049, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=300 id=1126 in=0
Called[8] Type=Default (100) Reason=CMDRdirect Keypad[8]
10:12:37 1643252mS CMARS: FORM: SIPPrimary - Received Number: 012529048
10:12:37 1643252mS CMARS: CMARSTargetingPending
10:12:37 1643340mS H323Evt: Recv: RegistrationRequest 10.0.2.161; Endpoints registered: 89; Endpoints in registration: 0
10:12:37 1643448mS PRN: 3049: Digit Pressed 0
10:12:37 1643448mS CMExtnRx: v=3049, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=300 id=1126 in=0
Called[0] Type=Default (100) Reason=CMDRdirect Keypad[0]
10:12:37 1643449mS CMARS: FORM: SIPPrimary - Received Number: 0125290480
10:12:37 1643449mS CMARS: CMARSTargetingPending
10:12:37 1643590mS PRN: 3049: Digit Pressed 0
10:12:37 1643590mS CMExtnRx: v=3049, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=300 id=1126 in=0
Called[0] Type=Default (100) Reason=CMDRdirect Keypad[0]
10:12:37 1643591mS CMARS: FORM: SIPPrimary - Received Number: 01252904800
10:12:37 1643592mS CMARS: CMARSTargetingPending
10:12:37 1643716mS PRN: Optimizing BTree Lists Completed...Started:1642989
10:12:38 1644332mS H323Evt: Recv: RegistrationRequest 10.0.2.160; Endpoints registered: 89; Endpoints in registration: 0
10:12:38 1644856mS RES: Wed 22/6/2016 10:12:38 FreeMem=43287404 42723164(4) CachedMem=564240 CMMsg=7(8) Buff=5200 1362 999 7403 4 Links=10781 BTree=12818 CPU=07.14% CPUStats=3/10/1171/14574/15623/1/0 MCR=0 MCW=0
10:12:38 1644856mS RES2: IP 500 V2 9.0.3.0 build 941 Tasks=58 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=175 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=5 SSA=1 TCP=197(TLS=2) TAPI=1 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
10:12:38 1644856mS RES4: XML MemObjs=61 PoolMem=2097152(1) FreeMem=2081872(1)
10:12:39 1645312mS CMExtnRxP: v=3001
CMShortCode
Line: type=NoLine 0 Call: lid=0 id=-1 in=0
ShortCode GetSystemInfo (99) = []
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ALaw
10:12:39 1645312mS CMExtnEvt: K Gill: ProcessShortCode feature=GetSystemInfo id=
10:12:39 1645313mS CMExtnTxP: v=3001
CMShortCode
Line: type=IPLine 250 Call: lid=0 id=-1 in=0
ShortCode GetSystemInfo (99) = [9.0.3.0 build 941] Calling[GreatPortland] Type=Default Plan=Default
Display [IP 500 V2]
Tag type=Text flags=0x1 [1,1,3,1,0,1,0.] [0x31 0x2c 0x31 0x2c 0x33 0x2c 0x31 0x2c 0x30 0x2c 0x31 0x2c 0x30 0x00 ]
Timed: 22/06/16 10:12
10:12:39 1645313mS CMExtnTx: v=3001, p1=0
CMShortCode
Line: type=IPLine 250 Call: lid=0 id=-1 in=0
ShortCode GetSystemInfo (99) = [9.0.3.0 build 941] Calling[GreatPortland] Type=Default Plan=Default
Display [IP 500 V2]
Tag type=Text flags=0x1 [1,1,3,1,0,1,0.] [0x31 0x2c 0x31 0x2c 0x33 0x2c 0x31 0x2c 0x30 0x2c 0x31 0x2c 0x30 0x00 ]
Timed: 22/06/16 10:12
10:12:39 1645656mS SIP Rx: UDP 10.0.2.191:5060 -> 10.0.2.200:5060
REGISTER sip:10.0.2.200 SIP/2.0
Via: SIP/2.0/UDP 10.0.2.191:5060;branch=z9hG4bK-45716644
From: "NT StarPhone" <sip:3091@10.0.2.200>;tag=1d41c3f3dfd79178o0
To: "NT StarPhone" <sip:3091@10.0.2.200>
Call-ID: 273d33ac-f3fbbbf7@10.0.2.191
CSeq: 37537 REGISTER
Max-Forwards: 70
Authorization: Digest username="3091",realm="ipoffice",nonce="e92cf43e444bee6d8a56",uri="sip:10.0.2.200",algorithm=MD5,response="5416887790e1118af385575c456e73ac"
Contact: "NT StarPhone" <sip:3091@10.0.2.191:5060>;expires=3600
P-Station-Name: ;mac=ccd539f3bb16; sn=CCQ1712038R
User-Agent: Cisco/SPA112-1.2.1(004)
Allow-Events: talk, hold, conference
P-Station-Name: ;mac=ccd539f3bb16; display=""; sn=CCQ1712038R
Content-Length: 0
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
Supported: replaces
10:12:39 1645661mS Sip: SIPDialog f4ac78ac created, dialogs 4
10:12:39 1645663mS SIP Tx: UDP 10.0.2.200:5060 -> 10.0.2.191:5060
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.0.2.191:5060;branch=z9hG4bK-45716644
From: "NT StarPhone" <sip:3091@10.0.2.200>;tag=1d41c3f3dfd79178o0
Call-ID: 273d33ac-f3fbbbf7@10.0.2.191
CSeq: 37537 REGISTER
User-Agent: IP Office 9.0.3.0 build 941
Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,REFER,NOTIFY,INFO,SUBSCRIBE,REGISTER,PUBLISH
Contact: <sip:3091@10.0.2.191:5060>
Date: Wed, 22 Jun 2016 09:12:38 GMT
Expires: 180
Supported: timer
Server: IP Office 9.0.3.0 build 941
To: "NT StarPhone" <sip:3091@10.0.2.200>;tag=34b188e8d061c6f0
Content-Length: 0
10:12:39 1645664mS Sip: SIPDialog f4ac78ac deleted, dialogs 3
10:12:40 1646091mS SIP Rx: UDP 10.0.2.184:5060 -> 10.0.2.200:5060
REGISTER sip:10.0.2.200 SIP/2.0
Via: SIP/2.0/UDP 10.0.2.184:5060;branch=z9hG4bK-ef557287
From: "NS StarPhone" <sip:3084@10.0.2.200>;tag=1118fb5b814780b7o0
To: "NS StarPhone" <sip:3084@10.0.2.200>
Call-ID: fa511daf-e7eba155@10.0.2.184
CSeq: 61048 REGISTER
Max-Forwards: 70
Authorization: Digest username="NS StarPhone",realm="ipoffice",nonce="517644c64a902d6b8f86",uri="sip:10.0.2.200",algorithm=MD5,response="836b811f0ff9ed876c7182478a148e25"
Contact: "NS StarPhone" <sip:3084@10.0.2.184:5060>;expires=3600
P-Station-Name: ;mac=b0faeb314094; sn=CCQ172604H0
User-Agent: Cisco/SPA112-1.2.1(004)
Allow-Events: talk, hold, conference
P-Station-Name: ;mac=b0faeb314094; display=""; sn=CCQ172604H0
Content-Length: 0
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
Supported: replaces
10:12:40 1646096mS Sip: SIPDialog f4ac78ac created, dialogs 4
10:12:40 1646099mS SIP Tx: UDP 10.0.2.200:5060 -> 10.0.2.184:5060
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.0.2.184:5060;branch=z9hG4bK-ef557287
From: "NS StarPhone" <sip:3084@10.0.2.200>;tag=1118fb5b814780b7o0
Call-ID: fa511daf-e7eba155@10.0.2.184
CSeq: 61048 REGISTER
User-Agent: IP Office 9.0.3.0 build 941
Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,REFER,NOTIFY,INFO,SUBSCRIBE,REGISTER,PUBLISH
Contact: <sip:3084@10.0.2.184:5060>
Date: Wed, 22 Jun 2016 09:12:40 GMT
Expires: 180
Supported: timer
Server: IP Office 9.0.3.0 build 941
To: "NS StarPhone" <sip:3084@10.0.2.200>;tag=f4c7c377a6b54581
Content-Length: 0
10:12:40 1646099mS Sip: SIPDialog f4ac78ac deleted, dialogs 3
10:12:40 1646372mS H323Evt: Recv: RegistrationRequest 10.0.2.163; Endpoints registered: 89; Endpoints in registration: 0
10:12:40 1646642mS H323Evt: Recv: RegistrationRequest 10.0.2.197; Endpoints registered: 89; Endpoints in registration: 0
10:12:40 1646777mS H323Evt: Recv: RegistrationRequest 10.0.2.140; Endpoints registered: 89; Endpoints in registration: 0
10:12:40 1646924mS CMARS: Case 1 - dial_delay_time: 3000 has expired - Resolve what we might have - Called Number: 01252904800 Addr: f4337a94
10:12:40 1646924mS CMARS: FORM: SIPPrimary - Received Number: 01252904800
10:12:40 1646925mS CMARS: FOUND A SHORT CODE - short_code: N; - Tel: N"@88.215.55.11" - Called_Party: 01252904800@88.215.55.11 - Line Group Id: 2
10:12:40 1646925mS CMARS: FindActiveARSByGroupID GroupID=2 - Not Found
10:12:40 1646925mS CMLRQ: FindActiveLRQByGroupID GroupID=2 - Not Found
10:12:40 1646926mS CMTARGET: Problem with Line Id: 17 - check_DNS 1 OperationalTest: 0, IP address: 88.215.63.11
10:12:40 1646926mS CMMap: a=2.1 b=0.0 Mapper::AllocateCodec allocated CMRTVocoder resource busy 2, total 42
10:12:40 1646927mS CMCallEvt: 0.1129.0 -1 BaseEP: NEW CMEndpoint f44e86bc TOTAL NOW=9 CALL_LIST=4
10:12:40 1646929mS CMARS: FOUND LINE - Line Id: 9 - using line group id: 2 - Called Number: 01252904800@88.215.55.11 - Calling Number: 3049
10:12:40 1646929mS CMARS: SEND Setup TO LINE
10:12:40 1646930mS CMCallEvt: 0.1129.0 36 Alog Trunk:9: StateChange: END=child CMCSIdle->CMCSOffering
10:12:40 1646930mS CMLineTx: v=9
CMSetup
Line: type=AnalogueLine 9 Call: lid=0 id=1129 in=0
Called[01252904800@88.215.55.11] Type=Default (100) Reason=CMDRdirect SndComp Calling[3049] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ALaw
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=R Russell Smith
IE CMIECallingPartyKName (226)(Type=CMNameDefault) name=Rob Russell Smith
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=R Russell Smith
IE CMIERespondingPartyKName (229)(Type=CMNameDefault) name=Rob Russell Smith
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=3049
IE CMIEDeviceDetail (231) 0a0002c800000466 LOCALE=eng HW=15 VER=9 class=CMDeviceH323Phone type=111 number=8049 channel=0 features=0x10000420 rx_gain=0 tx_gain=32 ep_callid=1126 ipaddr=10.0.2.200 apps=0 loc=0 em_loc=0 features2=0x0 is_spcall=0
IE CMIEMohSourceId (247) MOH Source = 255
Locale: eng
10:12:40 1646931mS CD: CALL: 300.1126.0 BState=Idle Cut=2 Music=0.0 Aend="R Russell Smith(3049)" (0.0) Bend="" [Line 9] (0.0) CalledNum=901252904800 () CallingNum=3049 (R Russell Smith) Internal=1 Time=6613 AState=Dialling
10:12:44 1650387mS PRN: Monitor Status IP 500 V2 9.0.3.0 build 941
10:12:44 1650387mS PRN: LAW=A PRI=1, BRI=0, ALOG=4, VCOMP=42, MDM=0, WAN=0, MODU=2 LANM=0 CkSRC=1 VMAIL=1(VER=3 TYP=1) 1-X=1 CALLS=4(TOT=36)
10:12:44 1650767mS RES: Wed 22/6/2016 10:12:44 FreeMem=43239428 42690356(4) CachedMem=549072 CMMsg=7(8) Buff=5200 1362 1000 7403 4 Links=10773 BTree=12817 CPU=05.00% CPUStats=1/4/1171/14712/15623/1/0 MCR=0 MCW=0
10:12:44 1650768mS RES2: IP 500 V2 9.0.3.0 build 941 Tasks=58 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=174 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=5 SSA=1 TCP=197(TLS=2) TAPI=1 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
10:12:44 1650768mS RES4: XML MemObjs=61 PoolMem=2097152(1) FreeMem=2081872(1)
10:12:44 1650931mS CD: CALL: 300.1126.0 BState=Idle Cut=2 Music=0.0 Aend="R Russell Smith(3049)" (0.0) Bend="" [Line 9] (0.0) CalledNum=901252904800 () CallingNum=3049 (R Russell Smith) Internal=1 Time=10613 AState=Dialling
10:12:45 1651876mS PRN: Monitor Status IP 500 V2 9.0.3.0 build 941
10:12:45 1651876mS PRN: LAW=A PRI=1, BRI=0, ALOG=4, VCOMP=42, MDM=0, WAN=0, MODU=2 LANM=0 CkSRC=1 VMAIL=1(VER=3 TYP=1) 1-X=1 CALLS=4(TOT=36)
10:12:45 1651935mS CMLineRx: v=9
CMReleaseComp
Line: type=AnalogueLine 9 Call: lid=0 id=1129 in=0
BChan: slot=5 chan=1
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=901252904800
IE CMIEDeviceDetail (231) 0a0002c800000469 LOCALE=eng HW=15 VER=9 class=CMDeviceAlogTrunk type=0 number=9 channel=0 features=0x1 rx_gain=32 tx_gain=32 ep_callid=1129 ipaddr=10.0.2.200 apps=0 loc=0 em_loc=0 features2=0x0 is_spcall=0
10:12:45 1651936mS CMARS: LINE ep Received: CMReleaseComp - child->state = CMCSOffering - ARS Call State = CMCSOverlapRecv
10:12:45 1651937mS CMCallEvt: 0.1129.0 -1 Alog Trunk:9: StateChange: END=X CMCSOffering->CMCSDelete
10:12:45 1651938mS CMARS: Target: Short_Code: N; - Line_Group_ID: 2 has been set to: CMARS_OUTOFSERVICE
10:12:45 1651938mS CMCallEvt: 0.1128.0 36 ARS for SIPPrimary: StateChange: END=B CMCSOverlapRecv->CMCSAccept
10:12:45 1651939mS CMCallEvt: 300.1126.0 36 R Russell Smith.0: StateChange: END=A CMCSDialling->CMCSRingBack
10:12:45 1651940mS CMExtnEvt: v=41 State, new=Alerting old=Dialling,0,0,R Russell Smith
10:12:45 1651940mS CMExtnTx: v=3049, p1=0
CMProgress
Line: type=IPLine 250 Call: lid=300 id=1126 in=0
IE CMIEProgressIndicator (30) cs=CMCSITUT (0), loc=CMLUser (0), pd=CMPDInbandPattern (8)
Display [WAITING_FOR_LINE]
Timed: 22/06/16 10:12
10:12:45 1651941mS CMCallEvt: 0.1129.0 -1 BaseEP: DELETE CMEndpoint f44e86bc TOTAL NOW=8 CALL_LIST=4
10:12:45 1651941mS CD: CALL: 300.1126.0 BState=Ringing Cut=3 Music=0.0 Aend="R Russell Smith(3049)" (0.0) Bend="" [] (0.0) CalledNum=901252904800 () CallingNum=3049 (R Russell Smith) Internal=1 Time=11623 AState=Ringing
10:12:45 1651945mS CMMap: a=21.11 b=0.0 DTMF::AllocateRAS allocated CMRTVoicemail resource busy 2, total 45
10:12:45 1651945mS CMMap: a=21.11 b=1.65535 T
10:12:45 1651945mS CMMap: PCG::AddToneGenerator g T[46] for cp[225]b0r1 append pcp[226]b0r1 (total 1)
10:12:45 1651946mS CMMap: a=2.18 b=0.0 IP::ReserveCodec pcp[226]b0r1 allocated CMRTVocoder resource busy 3, total 42, codec type 4
10:12:45 1651946mS CMMap: a=21.11 b=2.18 M22
10:12:45 1651947mS CMMap: PlatformConnectionAudioSAP::Bind pcp[226]b0r1 to 2.18
10:12:45 1651947mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[226]b0r1 Configure 2.18
10:12:45 1651947mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[226]b0r1 ConnectIndication 2.18
10:12:45 1651948mS CMMap: PCG::MapBChan pcp[225]b0r1 cp_b 0 other_cp_b 0 type CGTypeDTMF
10:12:45 1651948mS H323Evt: SetOperational 48 10.0.2.200:49158 to 1
10:12:45 1651948mS CMMap: DTMF:
layTones g T[46] ,EEEEE
10:12:45 1651948mS CMMap: Started playing tones, cp[225]b0r1 (from g null)
10:12:45 1651949mS CMMap: cp[225]b0r1 SetOperGroup from g null to g null not executed, playing tones in progress ,EEEEE
10:12:46 1652748mS H323Evt: Recv: RegistrationRequest 10.0.2.134; Endpoints registered: 89; Endpoints in registration: 0
10:12:46 1652938mS CMARS: MOVE TO ALTERNATE FORM: Main
10:12:46 1652938mS CMARS: FORM: Main - Received Number: 01252904800
10:12:46 1652938mS CMARS: FOUND A SHORT CODE - short_code: ? - Tel: . - Called_Party: 01252904800 - Line Group Id: 0
10:12:46 1652939mS CMARS: FindActiveARSByGroupID GroupID=0 - Not Found
10:12:46 1652939mS CMLRQ: FindActiveLRQByGroupID GroupID=0 - Not Found
10:12:46 1652939mS CMTARGET: Problem with Line Id: 17 - check_DNS 1 OperationalTest: 0, IP address: 88.215.63.11
10:12:46 1652940mS CMCallEvt: 0.1130.0 -1 BaseEP: NEW CMEndpoint f44e61f4 TOTAL NOW=9 CALL_LIST=4
10:12:46 1652942mS CMARS: FOUND LINE - Line Id: 1 - using line group id: 0 - Called Number: 01252904800 - Calling Number: 3049
10:12:46 1652942mS CMARS: SEND Setup TO LINE - ARSTimeout
10:12:46 1652943mS CMCallEvt: 0.1130.0 36 Q931 Trunk:1 CHAN=-1: StateChange: END=child CMCSIdle->CMCSOffering
10:12:46 1652943mS CMLineTx: v=1
CMSetup
Line: type=Q931Line 1 Call: lid=0 id=1130 in=0
Called[01252904800] Type=Unknown (0) Reason=CMDRdirect SndComp Calling[3049] Type=Unknown Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ALaw
Locale: eng
10:12:46 1652944mS CD: CALL: 300.1126.0 BState=Ringing Cut=3 Music=0.0 Aend="R Russell Smith(3049)" (0.0) Bend="" [Line 1] (0.0) CalledNum=901252904800 () CallingNum=3049 (R Russell Smith) Internal=1 Time=12626 AState=Ringing
10:12:46 1652946mS ISDNL3Evt: v=1 stacknum=1 State, new=Initiated, old=NullState id=1130
10:12:47 1653050mS H323Evt: Recv: RegistrationRequest 10.0.2.105; Endpoints registered: 89; Endpoints in registration: 0
10:12:47 1653056mS H323Evt: RTP(50t): 10.0.2.200/49158 10.0.2.149/52034 CODEC=Alaw64K(4) PKTSZ=160 RFC2833=off AGE=12712 SENT=50 (avg size=160) RECV=53 (avg size=160)
10:12:47 1653128mS ISDNL3Evt: v=1 stacknum=1 State, new=Proceeding, old=Initiated id=1130
10:12:47 1653129mS CMLineRx: v=1
CMProceeding
Line: type=Q931Line 1 Call: lid=0 id=1130 in=0
BChan: slot=0 chan=1
10:12:47 1653130mS CMARS: LINE ep Received: CMProceeding - child->state = CMCSOffering - ARS Call State = CMCSAccept
10:12:47 1653131mS CMARS: LINE IS NOW THE B END OF THE CALL - CMARSEndpoint::RequestEnd()
10:12:47 1653131mS CMARS: CMARSEndpoint::CallLost(cause=124) - Address: 0.1128.0 36 ARS for Main - Call State: CMCSAccept
10:12:47 1653132mS CMCallEvt: 0.1128.0 -1 ARS for Main: StateChange: END=X CMCSAccept->CMCSDelete
10:12:47 1653134mS CMCallEvt: 0.1130.0 36 Q931 Trunk:1 CHAN=1: StateChange: END=B CMCSOffering->CMCSAccept
10:12:47 1653136mS CMExtnTx: v=3049, p1=0
CMProceeding
Line: type=IPLine 250 Call: lid=300 id=1126 in=0
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=901252904800
IE CMIEDeviceDetail (231) 0a0002c80000046a LOCALE=eng HW=15 VER=9 class=CMDeviceISDNTrunk type=0 number=1 channel=1 features=0x1 rx_gain=32 tx_gain=32 ep_callid=1130 ipaddr=10.0.2.200 apps=0 loc=0 em_loc=0 features2=0x0 is_spcall=0
Timed: 22/06/16 10:12
10:12:47 1653137mS CMCallEvt: 0.1128.0 -1 BaseEP: DELETE CMEndpoint f4337a94 TOTAL NOW=8 CALL_LIST=4
10:12:47 1653138mS CD: CALL: 300.1126.0 BState=Ringing Cut=3 Music=0.0 Aend="R Russell Smith(3049)" (0.0) Bend="Line 1" [Line 1] (1.2) CalledNum=01252904800 () CallingNum=3049 (R Russell Smith) Internal=0 Time=12820 AState=Ringing
10:12:47 1653140mS CMMap: PCG::UnmapBChan pcp[225]b0r1 cp_b 0 other_cp_b 0
10:12:47 1653141mS H323Evt: SetOperational 48 10.0.2.200:49158 to 0
10:12:47 1653141mS CMMap: PCG::UnmapBChan pcp[226]b0r1 cp_b f50b7eac other_cp_b f50ab98c
10:12:47 1653141mS CMMap: a=21.11 b=2.18 M02
10:12:47 1653142mS CMMap: a=21.11 b=0.0 T0
10:12:47 1653143mS CMMap: a=21.11 b=0.0 DTMF::~DTMF freed CMRTUnknown resource busy 1, total 45
10:12:47 1653144mS CMMap: PCG::MapBChan pcp[225]b0r1 cp_b 0 other_cp_b 0 type CGTypeSimple
10:12:47 1653144mS CMMap: PCGS CPReserveCodec for the other end (pcp[225]b0r1) true
10:12:47 1653144mS CMMap: PCG::MapBChan pcp[99]b1r0 cp_b f506d03c other_cp_b f50bb68c type CGTypeSimple
10:12:47 1653145mS CMMap: a=2.1 b=1.2 M12
10:12:47 1653145mS CMMap: PlatformConnectionAudioSAP::Bind pcp[225]b0r1 to 2.1
10:12:47 1653145mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[225]b0r1 Configure 2.1
10:12:47 1653146mS CMMap: PlatformConnectionAudioSAP::ConnectVoice rtpRelay Open got rtpRelay ID: 3
10:12:47 1653146mS CMMap: PlatformConnectionAudioSAP::ConnectVoice rtpRelay Configure success
10:12:47 1653146mS CMMap: PlatformConnectionAudioSAP::ConnectVoice local IP addr 10.0.2.200:49158, Remote IP addr 10.0.2.149:52034
10:12:47 1653146mS CMMap: PlatformConnectionAudioSAP::ConnectVoice DSP IP addr 1.1.1.3:32768, telogyHost IP addr 1.1.1.1:10
Thanks for the help you clever bunch.
We have a site here that dials intermittently over there SIP trunk, some calls go out some fail over to ISDN Im banging my head against a brick wall now with this one. We didn't set up the SIP trunks and have now access to the router. We have checked and double checked the IPO and other than 1 thing that I spotted cant see any issues. Im going to try changing this one thing tonight [i](transport tab within sip trunk, network configuration "Use network topology info" currently set to "none" going to give lan 2 a try tonight)[/i]
Heres a trace of the last call that failed over SIP
10:12:33 1639925mS PRN: Monitor Status IP 500 V2 9.0.3.0 build 941
10:12:33 1639925mS PRN: LAW=A PRI=1, BRI=0, ALOG=4, VCOMP=42, MDM=0, WAN=0, MODU=2 LANM=0 CkSRC=1 VMAIL=1(VER=3 TYP=1) 1-X=1 CALLS=3(TOT=35)
10:12:34 1640316mS PRN: 3049: Digit Pressed 9
10:12:34 1640317mS CMCallEvt: 0.1126.0 -1 BaseEP: NEW CMEndpoint f43fb02c TOTAL NOW=7 CALL_LIST=3
10:12:34 1640317mS CMCallEvt: 0.1126.0 -1 R Russell Smith.-1: NEW CMExtnEndpoint f43fb02c, Name=R Russell Smith, Extn=3049, Phys Extn=3049
10:12:34 1640318mS CMCallEvt: CREATE CALL:36 (f437ac04)
10:12:34 1640319mS CMCallEvt: 0.1127.0 -1 BaseEP: NEW CMEndpoint f44847c4 TOTAL NOW=8 CALL_LIST=3
10:12:34 1640322mS CMExtnEvt: R Russell Smith: CMExtnHandler::SetCurrent( id: 0->1126 )
10:12:34 1640323mS CMExtnRx: v=3049, p1=0
CMSetup
Line: type=IPLine 250 Call: lid=300 id=1126 in=0
Called[] Type=Default (100) Reason=CMDRdirect Calling[3049] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ALaw
IE CMIEFastStartInfoData (6) 12 item(s)
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=R Russell Smith
IE CMIECallingPartyKName (226)(Type=CMNameDefault) name=Rob Russell Smith
10:12:34 1640324mS CMCallEvt: 300.1126.0 36 R Russell Smith.0: StateChange: END=A CMCSIdle->CMCSDialInitiated
10:12:34 1640324mS CMExtnEvt: v=41 State, new=Dialling old=Idle,0,0,R Russell Smith
10:12:34 1640325mS CMTARGET: 300.1126.0 36 R Russell Smith.0: LOOKUP CALL ROUTE: type=100 called_party= sub= calling=3049 dir=out complete=0 ses=0
10:12:34 1640325mS CMTARGET: 300.1126.0 36 R Russell Smith.0: ADD TARGET (N): number= type=100 depth=1 nobar=1 setorig=1 ses=0
10:12:34 1640326mS CMCallEvt: 300.1126.0 36 R Russell Smith.0: StateChange: END=A CMCSDialInitiated->CMCSDialling
10:12:34 1640330mS CMExtnTx: v=3049, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=300 id=1126 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
IE CMIESecurityData (253) 2 item(s)
CMSecurityElement RX_ONLY {
CMSRTPCryptoCapability none
Codecs list (size 4)
}
CMSecurityElement TX_ONLY {
CMSRTPCryptoCapability none
Codecs list (size 4)
}
Timed: 22/06/16 10:12
10:12:34 1640331mS CMExtnTx: v=3049, p1=8049
CMFacility
Line: type=IPLine 250 Call: lid=300 id=41 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
10:12:34 1640332mS CMExtnTx: v=3049, p1=0
CMSetupAck
Line: type=IPLine 250 Call: lid=300 id=1126 in=0
Timed: 22/06/16 10:12
10:12:34 1640332mS CMExtnTx: v=3049, p1=0
CMFacility
Line: type=IPLine 250 Call: lid=300 id=1126 in=0
IE CMIEFastStartInfoData (6) 2 item(s)
Timed: 22/06/16 10:12
10:12:34 1640333mS CMExtnTx: v=3049, p1=8049
CMFacility
Line: type=IPLine 250 Call: lid=300 id=41 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
10:12:34 1640333mS CMExtnTx: v=3049, p1=8049
CMFacility
Line: type=IPLine 250 Call: lid=300 id=41 in=1
IE CMIEFastStartInfoData (6) 2 item(s)
10:12:34 1640334mS CMExtnRx: v=3049, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=300 id=1126 in=0
Called[9] Type=Default (100) Reason=CMDRdirect Keypad[9]
10:12:34 1640339mS CD: CALL: 300.1126.0 BState=Idle Cut=0 Music=0.0 Aend="R Russell Smith(3049)" (0.0) Bend="" [] (0.0) CalledNum=9 () CallingNum=3049 (R Russell Smith) Internal=1 Time=21 AState=Dialling
10:12:34 1640343mS H323Evt: Recv: RegistrationRequest 10.0.2.155; Endpoints registered: 89; Endpoints in registration: 0
10:12:34 1640344mS H323Evt: SetOperational 48 10.0.2.200:0 to 0
10:12:34 1640851mS PRN: 3049: Digit Pressed 0
10:12:34 1640851mS CMExtnRx: v=3049, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=300 id=1126 in=0
Called[0] Type=Default (100) Reason=CMDRdirect Keypad[0]
10:12:35 1641310mS H323Evt: Recv: RegistrationRequest 10.0.2.146; Endpoints registered: 89; Endpoints in registration: 0
10:12:35 1641323mS H323Evt: Recv: RegistrationRequest 10.0.2.157; Endpoints registered: 89; Endpoints in registration: 0
10:12:35 1641499mS PRN: 3049: Digit Pressed 1
10:12:35 1641500mS CMExtnRx: v=3049, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=300 id=1126 in=0
Called[1] Type=Default (100) Reason=CMDRdirect Keypad[1]
10:12:35 1641920mS PRN: 3049: Digit Pressed 2
10:12:35 1641920mS CMExtnRx: v=3049, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=300 id=1126 in=0
Called[2] Type=Default (100) Reason=CMDRdirect Keypad[2]
10:12:35 1641921mS CMTARGET: 300.1126.0 36 R Russell Smith.0: CancelTimer CMTCDelayedProcessing
10:12:35 1641922mS CMTARGET: 300.1126.0 36 R Russell Smith.0: LOOKUP CALL ROUTE: type=100 called_party=9012 sub= calling=3049 dir=out complete=0 ses=0
10:12:35 1641922mS CMTARGET: 300.1126.0 36 R Russell Smith.0: ADD TARGET (N): number=9012 type=100 depth=1 nobar=1 setorig=1 ses=0
10:12:35 1641923mS CMTARGET: 300.1126.0 36 R Russell Smith.0: SYS SC: 9012 2 012 sc=type=Dial code=9N, num=N callinfop->sending_complete=0 secondary_dialtone=
10:12:35 1641924mS CMARS: FindActiveARSByGroupID GroupID=51 - Found
10:12:35 1641924mS CMARS: MakeCallTarget - Called Number: 012
10:12:35 1641924mS CMCallEvt: 0.1128.0 -1 BaseEP: NEW CMEndpoint f4337a94 TOTAL NOW=9 CALL_LIST=4
10:12:35 1641925mS CMTARGET: 300.1126.0 36 R Russell Smith.0: CancelTimer CMTCDialToneTimeout
10:12:35 1641926mS CMTARGET: 300.1126.0 36 R Russell Smith.0: INITIAL TARGETING SUCCEEDED
10:12:35 1641926mS CMTARGET: 300.1126.0 36 R Russell Smith.0: GetNoAnswerTimer:15
10:12:35 1641926mS CMCallEvt: 0.1127.0 36 TargetingEP: StateChange: END=B CMCSIdle->CMCSOffering
10:12:35 1641928mS CMCallEvt: 0.1128.0 36 ARS for SIPPrimary: StateChange: END=T CMCSIdle->CMCSOffering
10:12:35 1641928mS CMCallEvt: 0.1127.0 36 TargetingEP: RequestEnd 0.1128.0 36 ARS for SIPPrimary
10:12:35 1641929mS CMTARGET: 300.1126.0 36 R Russell Smith.0: CancelTimer CMTCNoAnswerTimeout
10:12:35 1641930mS CMCallEvt: 0.1128.0 36 ARS for SIPPrimary: StateChange: END=B CMCSOffering->CMCSOverlapRecv
10:12:35 1641930mS CMARS: FORM: SIPPrimary - Received Number: 012
10:12:35 1641931mS CMARS: CMARSTargetingPending
10:12:35 1641931mS CMCallEvt: 0.1127.0 -1 TargetingEP: StateChange: END=X CMCSOffering->CMCSDelete
10:12:35 1641931mS CMCallEvt: 0.1127.0 -1 BaseEP: DELETE CMEndpoint f44847c4 TOTAL NOW=8 CALL_LIST=4
10:12:35 1641932mS CD: CALL: 300.1126.0 BState=Idle Cut=2 Music=0.0 Aend="R Russell Smith(3049)" (0.0) Bend="" [] (0.0) CalledNum=9012 () CallingNum=3049 (R Russell Smith) Internal=1 Time=1614 AState=Dialling
10:12:36 1642106mS PRN: 3049: Digit Pressed 5
10:12:36 1642107mS CMExtnRx: v=3049, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=300 id=1126 in=0
Called[5] Type=Default (100) Reason=CMDRdirect Keypad[5]
10:12:36 1642108mS CMARS: FORM: SIPPrimary - Received Number: 0125
10:12:36 1642108mS CMARS: CMARSTargetingPending
10:12:36 1642298mS PRN: 3049: Digit Pressed 2
10:12:36 1642298mS CMExtnRx: v=3049, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=300 id=1126 in=0
Called[2] Type=Default (100) Reason=CMDRdirect Keypad[2]
10:12:36 1642299mS CMARS: FORM: SIPPrimary - Received Number: 01252
10:12:36 1642299mS CMARS: CMARSTargetingPending
10:12:36 1642324mS H323Evt: Recv: RegistrationRequest 10.0.2.159; Endpoints registered: 89; Endpoints in registration: 0
10:12:36 1642467mS H323Evt: Recv: RegistrationRequest 10.0.2.180; Endpoints registered: 89; Endpoints in registration: 0
10:12:36 1642522mS PRN: 3049: Digit Pressed 9
10:12:36 1642523mS CMExtnRx: v=3049, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=300 id=1126 in=0
Called[9] Type=Default (100) Reason=CMDRdirect Keypad[9]
10:12:36 1642524mS CMARS: FORM: SIPPrimary - Received Number: 012529
10:12:36 1642524mS CMARS: CMARSTargetingPending
10:12:36 1642732mS H323Evt: Recv: RegistrationRequest 10.0.2.195; Endpoints registered: 89; Endpoints in registration: 0
10:12:36 1642818mS PRN: 3049: Digit Pressed 0
10:12:36 1642819mS CMExtnRx: v=3049, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=300 id=1126 in=0
Called[0] Type=Default (100) Reason=CMDRdirect Keypad[0]
10:12:36 1642820mS CMARS: FORM: SIPPrimary - Received Number: 0125290
10:12:36 1642820mS CMARS: CMARSTargetingPending
10:12:37 1643036mS PRN: 3049: Digit Pressed 4
10:12:37 1643037mS CMExtnRx: v=3049, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=300 id=1126 in=0
Called[4] Type=Default (100) Reason=CMDRdirect Keypad[4]
10:12:37 1643037mS CMARS: FORM: SIPPrimary - Received Number: 01252904
10:12:37 1643038mS CMARS: CMARSTargetingPending
10:12:37 1643246mS SIP Tx: UDP 192.168.42.1:5060 -> 88.215.63.11:5060
OPTIONS sip:88.215.63.11 SIP/2.0
Via: SIP/2.0/UDP 192.168.42.1:5060;rport;branch=z9hG4bK76e11bce9efa3445749fa5442eb02b64
From: <sip:192.168.42.1>;tag=0366e2a395ba4514
To: <sip:88.215.63.11>
Call-ID: 2683f22db1d4fe423ef5cf3af121646d
CSeq: 1658998434 OPTIONS
Contact: <sip:192.168.42.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
10:12:37 1643251mS PRN: 3049: Digit Pressed 8
10:12:37 1643251mS CMExtnRx: v=3049, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=300 id=1126 in=0
Called[8] Type=Default (100) Reason=CMDRdirect Keypad[8]
10:12:37 1643252mS CMARS: FORM: SIPPrimary - Received Number: 012529048
10:12:37 1643252mS CMARS: CMARSTargetingPending
10:12:37 1643340mS H323Evt: Recv: RegistrationRequest 10.0.2.161; Endpoints registered: 89; Endpoints in registration: 0
10:12:37 1643448mS PRN: 3049: Digit Pressed 0
10:12:37 1643448mS CMExtnRx: v=3049, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=300 id=1126 in=0
Called[0] Type=Default (100) Reason=CMDRdirect Keypad[0]
10:12:37 1643449mS CMARS: FORM: SIPPrimary - Received Number: 0125290480
10:12:37 1643449mS CMARS: CMARSTargetingPending
10:12:37 1643590mS PRN: 3049: Digit Pressed 0
10:12:37 1643590mS CMExtnRx: v=3049, p1=0
CMInformation
Line: type=IPLine 250 Call: lid=300 id=1126 in=0
Called[0] Type=Default (100) Reason=CMDRdirect Keypad[0]
10:12:37 1643591mS CMARS: FORM: SIPPrimary - Received Number: 01252904800
10:12:37 1643592mS CMARS: CMARSTargetingPending
10:12:37 1643716mS PRN: Optimizing BTree Lists Completed...Started:1642989
10:12:38 1644332mS H323Evt: Recv: RegistrationRequest 10.0.2.160; Endpoints registered: 89; Endpoints in registration: 0
10:12:38 1644856mS RES: Wed 22/6/2016 10:12:38 FreeMem=43287404 42723164(4) CachedMem=564240 CMMsg=7(8) Buff=5200 1362 999 7403 4 Links=10781 BTree=12818 CPU=07.14% CPUStats=3/10/1171/14574/15623/1/0 MCR=0 MCW=0
10:12:38 1644856mS RES2: IP 500 V2 9.0.3.0 build 941 Tasks=58 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=175 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=5 SSA=1 TCP=197(TLS=2) TAPI=1 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
10:12:38 1644856mS RES4: XML MemObjs=61 PoolMem=2097152(1) FreeMem=2081872(1)
10:12:39 1645312mS CMExtnRxP: v=3001
CMShortCode
Line: type=NoLine 0 Call: lid=0 id=-1 in=0
ShortCode GetSystemInfo (99) = []
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ALaw
10:12:39 1645312mS CMExtnEvt: K Gill: ProcessShortCode feature=GetSystemInfo id=
10:12:39 1645313mS CMExtnTxP: v=3001
CMShortCode
Line: type=IPLine 250 Call: lid=0 id=-1 in=0
ShortCode GetSystemInfo (99) = [9.0.3.0 build 941] Calling[GreatPortland] Type=Default Plan=Default
Display [IP 500 V2]
Tag type=Text flags=0x1 [1,1,3,1,0,1,0.] [0x31 0x2c 0x31 0x2c 0x33 0x2c 0x31 0x2c 0x30 0x2c 0x31 0x2c 0x30 0x00 ]
Timed: 22/06/16 10:12
10:12:39 1645313mS CMExtnTx: v=3001, p1=0
CMShortCode
Line: type=IPLine 250 Call: lid=0 id=-1 in=0
ShortCode GetSystemInfo (99) = [9.0.3.0 build 941] Calling[GreatPortland] Type=Default Plan=Default
Display [IP 500 V2]
Tag type=Text flags=0x1 [1,1,3,1,0,1,0.] [0x31 0x2c 0x31 0x2c 0x33 0x2c 0x31 0x2c 0x30 0x2c 0x31 0x2c 0x30 0x00 ]
Timed: 22/06/16 10:12
10:12:39 1645656mS SIP Rx: UDP 10.0.2.191:5060 -> 10.0.2.200:5060
REGISTER sip:10.0.2.200 SIP/2.0
Via: SIP/2.0/UDP 10.0.2.191:5060;branch=z9hG4bK-45716644
From: "NT StarPhone" <sip:3091@10.0.2.200>;tag=1d41c3f3dfd79178o0
To: "NT StarPhone" <sip:3091@10.0.2.200>
Call-ID: 273d33ac-f3fbbbf7@10.0.2.191
CSeq: 37537 REGISTER
Max-Forwards: 70
Authorization: Digest username="3091",realm="ipoffice",nonce="e92cf43e444bee6d8a56",uri="sip:10.0.2.200",algorithm=MD5,response="5416887790e1118af385575c456e73ac"
Contact: "NT StarPhone" <sip:3091@10.0.2.191:5060>;expires=3600
P-Station-Name: ;mac=ccd539f3bb16; sn=CCQ1712038R
User-Agent: Cisco/SPA112-1.2.1(004)
Allow-Events: talk, hold, conference
P-Station-Name: ;mac=ccd539f3bb16; display=""; sn=CCQ1712038R
Content-Length: 0
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
Supported: replaces
10:12:39 1645661mS Sip: SIPDialog f4ac78ac created, dialogs 4
10:12:39 1645663mS SIP Tx: UDP 10.0.2.200:5060 -> 10.0.2.191:5060
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.0.2.191:5060;branch=z9hG4bK-45716644
From: "NT StarPhone" <sip:3091@10.0.2.200>;tag=1d41c3f3dfd79178o0
Call-ID: 273d33ac-f3fbbbf7@10.0.2.191
CSeq: 37537 REGISTER
User-Agent: IP Office 9.0.3.0 build 941
Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,REFER,NOTIFY,INFO,SUBSCRIBE,REGISTER,PUBLISH
Contact: <sip:3091@10.0.2.191:5060>
Date: Wed, 22 Jun 2016 09:12:38 GMT
Expires: 180
Supported: timer
Server: IP Office 9.0.3.0 build 941
To: "NT StarPhone" <sip:3091@10.0.2.200>;tag=34b188e8d061c6f0
Content-Length: 0
10:12:39 1645664mS Sip: SIPDialog f4ac78ac deleted, dialogs 3
10:12:40 1646091mS SIP Rx: UDP 10.0.2.184:5060 -> 10.0.2.200:5060
REGISTER sip:10.0.2.200 SIP/2.0
Via: SIP/2.0/UDP 10.0.2.184:5060;branch=z9hG4bK-ef557287
From: "NS StarPhone" <sip:3084@10.0.2.200>;tag=1118fb5b814780b7o0
To: "NS StarPhone" <sip:3084@10.0.2.200>
Call-ID: fa511daf-e7eba155@10.0.2.184
CSeq: 61048 REGISTER
Max-Forwards: 70
Authorization: Digest username="NS StarPhone",realm="ipoffice",nonce="517644c64a902d6b8f86",uri="sip:10.0.2.200",algorithm=MD5,response="836b811f0ff9ed876c7182478a148e25"
Contact: "NS StarPhone" <sip:3084@10.0.2.184:5060>;expires=3600
P-Station-Name: ;mac=b0faeb314094; sn=CCQ172604H0
User-Agent: Cisco/SPA112-1.2.1(004)
Allow-Events: talk, hold, conference
P-Station-Name: ;mac=b0faeb314094; display=""; sn=CCQ172604H0
Content-Length: 0
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
Supported: replaces
10:12:40 1646096mS Sip: SIPDialog f4ac78ac created, dialogs 4
10:12:40 1646099mS SIP Tx: UDP 10.0.2.200:5060 -> 10.0.2.184:5060
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.0.2.184:5060;branch=z9hG4bK-ef557287
From: "NS StarPhone" <sip:3084@10.0.2.200>;tag=1118fb5b814780b7o0
Call-ID: fa511daf-e7eba155@10.0.2.184
CSeq: 61048 REGISTER
User-Agent: IP Office 9.0.3.0 build 941
Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,REFER,NOTIFY,INFO,SUBSCRIBE,REGISTER,PUBLISH
Contact: <sip:3084@10.0.2.184:5060>
Date: Wed, 22 Jun 2016 09:12:40 GMT
Expires: 180
Supported: timer
Server: IP Office 9.0.3.0 build 941
To: "NS StarPhone" <sip:3084@10.0.2.200>;tag=f4c7c377a6b54581
Content-Length: 0
10:12:40 1646099mS Sip: SIPDialog f4ac78ac deleted, dialogs 3
10:12:40 1646372mS H323Evt: Recv: RegistrationRequest 10.0.2.163; Endpoints registered: 89; Endpoints in registration: 0
10:12:40 1646642mS H323Evt: Recv: RegistrationRequest 10.0.2.197; Endpoints registered: 89; Endpoints in registration: 0
10:12:40 1646777mS H323Evt: Recv: RegistrationRequest 10.0.2.140; Endpoints registered: 89; Endpoints in registration: 0
10:12:40 1646924mS CMARS: Case 1 - dial_delay_time: 3000 has expired - Resolve what we might have - Called Number: 01252904800 Addr: f4337a94
10:12:40 1646924mS CMARS: FORM: SIPPrimary - Received Number: 01252904800
10:12:40 1646925mS CMARS: FOUND A SHORT CODE - short_code: N; - Tel: N"@88.215.55.11" - Called_Party: 01252904800@88.215.55.11 - Line Group Id: 2
10:12:40 1646925mS CMARS: FindActiveARSByGroupID GroupID=2 - Not Found
10:12:40 1646925mS CMLRQ: FindActiveLRQByGroupID GroupID=2 - Not Found
10:12:40 1646926mS CMTARGET: Problem with Line Id: 17 - check_DNS 1 OperationalTest: 0, IP address: 88.215.63.11
10:12:40 1646926mS CMMap: a=2.1 b=0.0 Mapper::AllocateCodec allocated CMRTVocoder resource busy 2, total 42
10:12:40 1646927mS CMCallEvt: 0.1129.0 -1 BaseEP: NEW CMEndpoint f44e86bc TOTAL NOW=9 CALL_LIST=4
10:12:40 1646929mS CMARS: FOUND LINE - Line Id: 9 - using line group id: 2 - Called Number: 01252904800@88.215.55.11 - Calling Number: 3049
10:12:40 1646929mS CMARS: SEND Setup TO LINE
10:12:40 1646930mS CMCallEvt: 0.1129.0 36 Alog Trunk:9: StateChange: END=child CMCSIdle->CMCSOffering
10:12:40 1646930mS CMLineTx: v=9
CMSetup
Line: type=AnalogueLine 9 Call: lid=0 id=1129 in=0
Called[01252904800@88.215.55.11] Type=Default (100) Reason=CMDRdirect SndComp Calling[3049] Type=Internal Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ALaw
IE CMIECallingPartyName (110)(Type=CMNameDefault) name=R Russell Smith
IE CMIECallingPartyKName (226)(Type=CMNameDefault) name=Rob Russell Smith
IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=R Russell Smith
IE CMIERespondingPartyKName (229)(Type=CMNameDefault) name=Rob Russell Smith
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=3049
IE CMIEDeviceDetail (231) 0a0002c800000466 LOCALE=eng HW=15 VER=9 class=CMDeviceH323Phone type=111 number=8049 channel=0 features=0x10000420 rx_gain=0 tx_gain=32 ep_callid=1126 ipaddr=10.0.2.200 apps=0 loc=0 em_loc=0 features2=0x0 is_spcall=0
IE CMIEMohSourceId (247) MOH Source = 255
Locale: eng
10:12:40 1646931mS CD: CALL: 300.1126.0 BState=Idle Cut=2 Music=0.0 Aend="R Russell Smith(3049)" (0.0) Bend="" [Line 9] (0.0) CalledNum=901252904800 () CallingNum=3049 (R Russell Smith) Internal=1 Time=6613 AState=Dialling
10:12:44 1650387mS PRN: Monitor Status IP 500 V2 9.0.3.0 build 941
10:12:44 1650387mS PRN: LAW=A PRI=1, BRI=0, ALOG=4, VCOMP=42, MDM=0, WAN=0, MODU=2 LANM=0 CkSRC=1 VMAIL=1(VER=3 TYP=1) 1-X=1 CALLS=4(TOT=36)
10:12:44 1650767mS RES: Wed 22/6/2016 10:12:44 FreeMem=43239428 42690356(4) CachedMem=549072 CMMsg=7(8) Buff=5200 1362 1000 7403 4 Links=10773 BTree=12817 CPU=05.00% CPUStats=1/4/1171/14712/15623/1/0 MCR=0 MCW=0
10:12:44 1650768mS RES2: IP 500 V2 9.0.3.0 build 941 Tasks=58 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=174 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=5 SSA=1 TCP=197(TLS=2) TAPI=1 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
10:12:44 1650768mS RES4: XML MemObjs=61 PoolMem=2097152(1) FreeMem=2081872(1)
10:12:44 1650931mS CD: CALL: 300.1126.0 BState=Idle Cut=2 Music=0.0 Aend="R Russell Smith(3049)" (0.0) Bend="" [Line 9] (0.0) CalledNum=901252904800 () CallingNum=3049 (R Russell Smith) Internal=1 Time=10613 AState=Dialling
10:12:45 1651876mS PRN: Monitor Status IP 500 V2 9.0.3.0 build 941
10:12:45 1651876mS PRN: LAW=A PRI=1, BRI=0, ALOG=4, VCOMP=42, MDM=0, WAN=0, MODU=2 LANM=0 CkSRC=1 VMAIL=1(VER=3 TYP=1) 1-X=1 CALLS=4(TOT=36)
10:12:45 1651935mS CMLineRx: v=9
CMReleaseComp
Line: type=AnalogueLine 9 Call: lid=0 id=1129 in=0
BChan: slot=5 chan=1
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=901252904800
IE CMIEDeviceDetail (231) 0a0002c800000469 LOCALE=eng HW=15 VER=9 class=CMDeviceAlogTrunk type=0 number=9 channel=0 features=0x1 rx_gain=32 tx_gain=32 ep_callid=1129 ipaddr=10.0.2.200 apps=0 loc=0 em_loc=0 features2=0x0 is_spcall=0
10:12:45 1651936mS CMARS: LINE ep Received: CMReleaseComp - child->state = CMCSOffering - ARS Call State = CMCSOverlapRecv
10:12:45 1651937mS CMCallEvt: 0.1129.0 -1 Alog Trunk:9: StateChange: END=X CMCSOffering->CMCSDelete
10:12:45 1651938mS CMARS: Target: Short_Code: N; - Line_Group_ID: 2 has been set to: CMARS_OUTOFSERVICE
10:12:45 1651938mS CMCallEvt: 0.1128.0 36 ARS for SIPPrimary: StateChange: END=B CMCSOverlapRecv->CMCSAccept
10:12:45 1651939mS CMCallEvt: 300.1126.0 36 R Russell Smith.0: StateChange: END=A CMCSDialling->CMCSRingBack
10:12:45 1651940mS CMExtnEvt: v=41 State, new=Alerting old=Dialling,0,0,R Russell Smith
10:12:45 1651940mS CMExtnTx: v=3049, p1=0
CMProgress
Line: type=IPLine 250 Call: lid=300 id=1126 in=0
IE CMIEProgressIndicator (30) cs=CMCSITUT (0), loc=CMLUser (0), pd=CMPDInbandPattern (8)
Display [WAITING_FOR_LINE]
Timed: 22/06/16 10:12
10:12:45 1651941mS CMCallEvt: 0.1129.0 -1 BaseEP: DELETE CMEndpoint f44e86bc TOTAL NOW=8 CALL_LIST=4
10:12:45 1651941mS CD: CALL: 300.1126.0 BState=Ringing Cut=3 Music=0.0 Aend="R Russell Smith(3049)" (0.0) Bend="" [] (0.0) CalledNum=901252904800 () CallingNum=3049 (R Russell Smith) Internal=1 Time=11623 AState=Ringing
10:12:45 1651945mS CMMap: a=21.11 b=0.0 DTMF::AllocateRAS allocated CMRTVoicemail resource busy 2, total 45
10:12:45 1651945mS CMMap: a=21.11 b=1.65535 T
10:12:45 1651945mS CMMap: PCG::AddToneGenerator g T[46] for cp[225]b0r1 append pcp[226]b0r1 (total 1)
10:12:45 1651946mS CMMap: a=2.18 b=0.0 IP::ReserveCodec pcp[226]b0r1 allocated CMRTVocoder resource busy 3, total 42, codec type 4
10:12:45 1651946mS CMMap: a=21.11 b=2.18 M22
10:12:45 1651947mS CMMap: PlatformConnectionAudioSAP::Bind pcp[226]b0r1 to 2.18
10:12:45 1651947mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[226]b0r1 Configure 2.18
10:12:45 1651947mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[226]b0r1 ConnectIndication 2.18
10:12:45 1651948mS CMMap: PCG::MapBChan pcp[225]b0r1 cp_b 0 other_cp_b 0 type CGTypeDTMF
10:12:45 1651948mS H323Evt: SetOperational 48 10.0.2.200:49158 to 1
10:12:45 1651948mS CMMap: DTMF:
10:12:45 1651948mS CMMap: Started playing tones, cp[225]b0r1 (from g null)
10:12:45 1651949mS CMMap: cp[225]b0r1 SetOperGroup from g null to g null not executed, playing tones in progress ,EEEEE
10:12:46 1652748mS H323Evt: Recv: RegistrationRequest 10.0.2.134; Endpoints registered: 89; Endpoints in registration: 0
10:12:46 1652938mS CMARS: MOVE TO ALTERNATE FORM: Main
10:12:46 1652938mS CMARS: FORM: Main - Received Number: 01252904800
10:12:46 1652938mS CMARS: FOUND A SHORT CODE - short_code: ? - Tel: . - Called_Party: 01252904800 - Line Group Id: 0
10:12:46 1652939mS CMARS: FindActiveARSByGroupID GroupID=0 - Not Found
10:12:46 1652939mS CMLRQ: FindActiveLRQByGroupID GroupID=0 - Not Found
10:12:46 1652939mS CMTARGET: Problem with Line Id: 17 - check_DNS 1 OperationalTest: 0, IP address: 88.215.63.11
10:12:46 1652940mS CMCallEvt: 0.1130.0 -1 BaseEP: NEW CMEndpoint f44e61f4 TOTAL NOW=9 CALL_LIST=4
10:12:46 1652942mS CMARS: FOUND LINE - Line Id: 1 - using line group id: 0 - Called Number: 01252904800 - Calling Number: 3049
10:12:46 1652942mS CMARS: SEND Setup TO LINE - ARSTimeout
10:12:46 1652943mS CMCallEvt: 0.1130.0 36 Q931 Trunk:1 CHAN=-1: StateChange: END=child CMCSIdle->CMCSOffering
10:12:46 1652943mS CMLineTx: v=1
CMSetup
Line: type=Q931Line 1 Call: lid=0 id=1130 in=0
Called[01252904800] Type=Unknown (0) Reason=CMDRdirect SndComp Calling[3049] Type=Unknown Plan=Default
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ALaw
Locale: eng
10:12:46 1652944mS CD: CALL: 300.1126.0 BState=Ringing Cut=3 Music=0.0 Aend="R Russell Smith(3049)" (0.0) Bend="" [Line 1] (0.0) CalledNum=901252904800 () CallingNum=3049 (R Russell Smith) Internal=1 Time=12626 AState=Ringing
10:12:46 1652946mS ISDNL3Evt: v=1 stacknum=1 State, new=Initiated, old=NullState id=1130
10:12:47 1653050mS H323Evt: Recv: RegistrationRequest 10.0.2.105; Endpoints registered: 89; Endpoints in registration: 0
10:12:47 1653056mS H323Evt: RTP(50t): 10.0.2.200/49158 10.0.2.149/52034 CODEC=Alaw64K(4) PKTSZ=160 RFC2833=off AGE=12712 SENT=50 (avg size=160) RECV=53 (avg size=160)
10:12:47 1653128mS ISDNL3Evt: v=1 stacknum=1 State, new=Proceeding, old=Initiated id=1130
10:12:47 1653129mS CMLineRx: v=1
CMProceeding
Line: type=Q931Line 1 Call: lid=0 id=1130 in=0
BChan: slot=0 chan=1
10:12:47 1653130mS CMARS: LINE ep Received: CMProceeding - child->state = CMCSOffering - ARS Call State = CMCSAccept
10:12:47 1653131mS CMARS: LINE IS NOW THE B END OF THE CALL - CMARSEndpoint::RequestEnd()
10:12:47 1653131mS CMARS: CMARSEndpoint::CallLost(cause=124) - Address: 0.1128.0 36 ARS for Main - Call State: CMCSAccept
10:12:47 1653132mS CMCallEvt: 0.1128.0 -1 ARS for Main: StateChange: END=X CMCSAccept->CMCSDelete
10:12:47 1653134mS CMCallEvt: 0.1130.0 36 Q931 Trunk:1 CHAN=1: StateChange: END=B CMCSOffering->CMCSAccept
10:12:47 1653136mS CMExtnTx: v=3049, p1=0
CMProceeding
Line: type=IPLine 250 Call: lid=300 id=1126 in=0
IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=901252904800
IE CMIEDeviceDetail (231) 0a0002c80000046a LOCALE=eng HW=15 VER=9 class=CMDeviceISDNTrunk type=0 number=1 channel=1 features=0x1 rx_gain=32 tx_gain=32 ep_callid=1130 ipaddr=10.0.2.200 apps=0 loc=0 em_loc=0 features2=0x0 is_spcall=0
Timed: 22/06/16 10:12
10:12:47 1653137mS CMCallEvt: 0.1128.0 -1 BaseEP: DELETE CMEndpoint f4337a94 TOTAL NOW=8 CALL_LIST=4
10:12:47 1653138mS CD: CALL: 300.1126.0 BState=Ringing Cut=3 Music=0.0 Aend="R Russell Smith(3049)" (0.0) Bend="Line 1" [Line 1] (1.2) CalledNum=01252904800 () CallingNum=3049 (R Russell Smith) Internal=0 Time=12820 AState=Ringing
10:12:47 1653140mS CMMap: PCG::UnmapBChan pcp[225]b0r1 cp_b 0 other_cp_b 0
10:12:47 1653141mS H323Evt: SetOperational 48 10.0.2.200:49158 to 0
10:12:47 1653141mS CMMap: PCG::UnmapBChan pcp[226]b0r1 cp_b f50b7eac other_cp_b f50ab98c
10:12:47 1653141mS CMMap: a=21.11 b=2.18 M02
10:12:47 1653142mS CMMap: a=21.11 b=0.0 T0
10:12:47 1653143mS CMMap: a=21.11 b=0.0 DTMF::~DTMF freed CMRTUnknown resource busy 1, total 45
10:12:47 1653144mS CMMap: PCG::MapBChan pcp[225]b0r1 cp_b 0 other_cp_b 0 type CGTypeSimple
10:12:47 1653144mS CMMap: PCGS CPReserveCodec for the other end (pcp[225]b0r1) true
10:12:47 1653144mS CMMap: PCG::MapBChan pcp[99]b1r0 cp_b f506d03c other_cp_b f50bb68c type CGTypeSimple
10:12:47 1653145mS CMMap: a=2.1 b=1.2 M12
10:12:47 1653145mS CMMap: PlatformConnectionAudioSAP::Bind pcp[225]b0r1 to 2.1
10:12:47 1653145mS CMMap: PlatformConnectionAudioSAP::ConnectVoice pcp[225]b0r1 Configure 2.1
10:12:47 1653146mS CMMap: PlatformConnectionAudioSAP::ConnectVoice rtpRelay Open got rtpRelay ID: 3
10:12:47 1653146mS CMMap: PlatformConnectionAudioSAP::ConnectVoice rtpRelay Configure success
10:12:47 1653146mS CMMap: PlatformConnectionAudioSAP::ConnectVoice local IP addr 10.0.2.200:49158, Remote IP addr 10.0.2.149:52034
10:12:47 1653146mS CMMap: PlatformConnectionAudioSAP::ConnectVoice DSP IP addr 1.1.1.3:32768, telogyHost IP addr 1.1.1.1:10
Thanks for the help you clever bunch.