UNICODE-UTF8 enu ********** SysMonitor v9.1.8.0 build 172 ********** ********** contact made with 172.30.20.68 at 10:03:55 13/3/2017 ********** ********** System (172.30.20.68) has been up and running for 46days, 21hrs, 42mins and 1sec(4052521222mS) ********** ********** Warning: TEXT File Logging selected ********** ********** Warning: TEXT Logging to C:\Program Files (x86)\Avaya\IP Office\Monitor\\TMP1.$$$ File: STARTED on 13/3/2017 10:03:55 ********** 4052521222mS PRN: Monitor Started IP=172.30.20.103 IP 500 V2 9.1.6.0 build 153 ICUCarlosGabado (Supports Unicode, System Locale is default) 4052521222mS PRN: LAW=U PRI=1, BRI=0, ALOG=8, VCOMP=20, MDM=0, WAN=0, MODU=0 LANM=0 CkSRC=9 VMAIL=1(VER=3 TYP=1) 1-X=1 CALLS=1(TOT=2260) 10:08:58 4052521327mS RES: Mon 13/3/2017 10:08:58 FreeMem=53780060 Heap=52855144(0) Cache=924916 MemObjs=12037(18126) CMMsg=8(10) ASN=0 Buff=5200 1375 1000 7351 5 Links=56006(56365) BTree=808(2106) CPU=03.35% CPUStats=03.75%/1/4/1163/13716/14978/00.00%/0 /02.63% MCR=0 MCW=0 10:08:58 4052521328mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=55 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=67 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=0 TCP=205(TLS=91) TAPI=1 Partner=25 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034 10:08:58 4052521328mS RES4: XML MemObjs=63 PoolMem=4748404(2) FreePoolMem=4733100(0) 10:08:58 4052521328mS RES5: CLog MemObjs=519 FreePoolMem(Objs)=4212(81) TotalMem=198150 10:09:01 4052524222mS PRN: +++ START OF ALARM LOG DUMP +++ 10:09:01 4052524222mS PRN: ALARM: 21/12/2012 12:03:39 IP 500 V2 8.0(51) CRIT RAISED addr=00000000 d=0 pc=f00b9748 f0006688 f02e77c0 f02e778c 00000000 00000000 10:09:01 4052524222mS PRN: ALARM: 14/12/2015 13:26:49 IP 500 V2 8.1(65) CRIT RAISED addr=000000d8 d=5 pc=f0316b34 f041dd54 f03f71b0 f03fc308 f03fb6a4 f0447a98 10:09:01 4052524222mS PRN: +++ END OF ALARM LOG DUMP +++ 10:09:02 4052525222mS PRN: +++ START OF UDP MONITOR CLIENT DUMP +++ 10:09:02 4052525222mS PRN: CLIENT: IPAddress=172.30.20.67 UDPPort=59000 LastReceived=4052523490(1732) LastSent=4052524829(393) LastOldUpdate=4052499659(25563) SentPackets=48 MissedPackets=0 OldSentPackets=126 OldMissedPackets=0 10:09:02 4052525222mS PRN: CLIENT: IPAddress=172.30.20.103 UDPPort=61557 LastReceived=4052521832(3390) LastSent=4052525222(0) LastOldUpdate=4052521221(4001) SentPackets=22 MissedPackets=0 OldSentPackets=0 OldMissedPackets=0 10:09:02 4052525222mS PRN: ++++ END OF UDP MONITOR CLIENT DUMP ++++ 10:09:03 4052526330mS RES: Mon 13/3/2017 10:09:03 FreeMem=53771736 Heap=52855144(0) Cache=916592 MemObjs=12040(18126) CMMsg=8(10) ASN=0 Buff=5200 1375 1000 7350 5 Links=56007(56365) BTree=808(2106) CPU=03.25% CPUStats=02.56%/1/4/1163/13794/14978/00.01%/0 /02.65% MCR=0 MCW=0 10:09:03 4052526330mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=56 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=68 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=0 TCP=205(TLS=91) TAPI=1 Partner=25 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034 10:09:03 4052526330mS RES4: XML MemObjs=63 PoolMem=4748404(2) FreePoolMem=4733100(0) 10:09:03 4052526330mS RES5: CLog MemObjs=519 FreePoolMem(Objs)=4212(81) TotalMem=198150 10:09:03 4052526422mS PRN: +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++ 10:09:03 4052526422mS PRN: + loader: 1.35 10:09:03 4052526422mS PRN: + cpu: id 12 board 4 pld 25 type c10 options a802 10:09:03 4052526422mS PRN: + cpu: sn 11WZ1050003F 10:09:03 4052526422mS PRN: + fpga: id 1 issue 0 build 827 10:09:03 4052526422mS PRN: +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++ 10:09:03 4052526422mS PRN: ++++++++++++++++++++ LIST OF MODULES ++++++++++++++++++++ 10:09:03 4052526422mS PRN: +------------------------------------------------------------ 10:09:03 4052526422mS PRN: + Slot 1: Base COMBO6210 Board=0x01 PLD=0x04 10:09:03 4052526422mS PRN: + Mezzanine ATM4 Board=0x03 PLD=0x07 10:09:03 4052526422mS PRN: +------------------------------------------------------------ 10:09:03 4052526423mS PRN: + Slot 2: Base COMBO6210 Board=0x02 PLD=0x04 10:09:03 4052526423mS PRN: + Mezzanine ATM4 Board=0x05 PLD=0x07 10:09:03 4052526423mS PRN: +------------------------------------------------------------ 10:09:03 4052526423mS PRN: + Slot 3: Base DIGSTA8 Board=0x13 PLD=0x06 10:09:03 4052526423mS PRN: + Mezzanine PRIS U Board=0x03 PLD=0x0a 10:09:03 4052526423mS PRN: +------------------------------------------------------------ 10:09:03 4052526423mS PRN: + Slot 4: Base NONE 10:09:03 4052526423mS PRN: + Mezzanine NONE 10:09:03 4052526423mS PRN: +------------------------------------------------------------ 10:09:03 4052526423mS PRN: +++++++++++++++++ END OF LIST OF MODULES +++++++++++++++ 10:09:03 4052526423mS PRN: +++++++++++++++++ LIST OF MEMORY CARDS ++++++++++++++++++ 10:09:03 4052526423mS PRN: +------------------------------------------------------------ 10:09:03 4052526423mS PRN: + System SD Card: MNTD 10:09:03 4052526423mS PRN: + CID Register: 0x03534453443034478005ef098300a44b 10:09:03 4052526424mS PRN: + CSD Register: 0x400e00325b5900001d8a7f800a4040b9 10:09:03 4052526424mS PRN: + SCR Register: 0x0235800000000000 10:09:03 4052526424mS PRN: + OCR Register: 0xc0ff8000 10:09:03 4052526427mS PRN: + Status Register: 0x0000000002000000030390000d05 10:09:03 4052526427mS PRN: +------------------------------------------------------------ 10:09:03 4052526427mS PRN: + Optional SD Card: UMNT 10:09:03 4052526427mS PRN: +------------------------------------------------------------ 10:09:03 4052526427mS PRN: ++++++++++++++ END OF LIST OF MEMORY CARDS +++++++++++++ 10:09:03 4052526427mS PRN: ++++++++++++++++++++ MEMORY CAPTURE +++++++++++++++++++++ 10:09:03 4052526427mS PRN: +------------------------------------------------------------ 10:09:03 4052526427mS PRN: + 0x00000012, 0x00000000, 0x00000000, 0x00000071, 0x00000000 10:09:03 4052526427mS PRN: + 0x00000001, 0x00000000, 0x0000006f, 0x00000000, 0x00000000 10:09:03 4052526427mS PRN: + 0x00000000, 0x00000000, 0x00000000, 0x00000071, 0x00000000 10:09:03 4052526427mS PRN: + 0x00000002, 0x00000000, 0x00000000, 0x00000000, 0x00000000 10:09:03 4052526427mS PRN: + 0x00000000, 0x00000000, 0x00000000, 0x00000000, 0x00000f5a 10:09:03 4052526427mS PRN: + 0x00000000, 0x00000000, 0x00000000, 0x00000000, 0x00000000 10:09:03 4052526427mS PRN: + 0x00000000, 0x00000000, 0x00000000, 0x00000000, 0x00000000 10:09:03 4052526428mS PRN: + 0x00000000, 0x00000000, 0x00000000, 0x00000000, 0x00000000 10:09:03 4052526428mS PRN: + 0x00000000, 0x50d21223, 0x521e11c5, 0x488aa7b6, 0x955e869c 10:09:03 4052526428mS PRN: + 0x00000000, 0x00000000, 0x00000000, 0x00000000, 0x00000000 10:09:03 4052526428mS PRN: +------------------------------------------------------------ 10:09:03 4052526428mS PRN: +++++++++++++++++ END OF MEMORY CAPTURE ++++++++++++++++ 10:09:07 4052530794mS SIP Tx: UDP 10.1.10.20:5060 -> 10.1.10.150:5060 REGISTER sip:10.1.10.150 SIP/2.0 Via: SIP/2.0/UDP 10.1.10.20:5060;rport;branch=z9hG4bK6a7c2ef8c69525cb6ff57231a251302b From: ;tag=b5721b6d62fd540c To: Call-ID: 3cc724274f214f0986cf86c3df86a65f CSeq: 1228661098 REGISTER Contact: Expires: 3600 Authorization: Digest username="sip0000001_aciaegis",realm="fe-4a2b-6w.coredial.com",nonce="5399b228",response="5d4f032c9fb05e3aad1f11063f2d207e",uri="sip:10.1.10.150" Max-Forwards: 70 User-Agent: IP Office 9.1.6.0 build 153 Supported: timer Content-Length: 0 10:09:18 4052541012mS Sip: SIP Line (17): Options timer expired 10:09:18 4052541012mS Sip: SIP Line (17): Setting options timer 120 seconds 10:09:18 4052541013mS Sip: SIPDialog f1845ee8 created, dialogs 2 txn_keys 3 10:09:18 4052541014mS Sip: (f1845ee8) OPTIONS SENT TO 10.1.10.150 5060 10:09:18 4052541014mS SIP Tx: UDP 10.1.10.20:5060 -> 10.1.10.150:5060 OPTIONS sip:10.1.10.150 SIP/2.0 Via: SIP/2.0/UDP 10.1.10.20:5060;rport;branch=z9hG4bK1d93da1d9ee9023f5343e88f1a1d4bc7 From: ;tag=7388cb06ee52506a To: Call-ID: 4c9f060bf1dc708db91b631ac80f19fe CSeq: 939207411 OPTIONS Contact: Max-Forwards: 70 Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,INFO,REFER,NOTIFY Supported: timer User-Agent: IP Office 9.1.6.0 build 153 Content-Length: 0 10:09:18 4052541019mS SIP Rx: UDP 10.1.10.150:5060 -> 10.1.10.20:5060 SIP/2.0 200 OK Via: SIP/2.0/UDP 10.1.10.20:5060;rport;branch=z9hG4bK1d93da1d9ee9023f5343e88f1a1d4bc7 From: ;tag=7388cb06ee52506a To: Call-ID: 4c9f060bf1dc708db91b631ac80f19fe CSeq: 939207411 OPTIONS Contact: Content-Length: 0 10:09:18 4052541021mS Sip: (f1845ee8) Process SIP response dialog f1845ee8, method OPTIONS, CodeNum 200 in state SIPDialog::INITIAL(0) 10:09:18 4052541021mS Sip: (f1845ee8) UpdateSIPCallState SIPDialog::INITIAL(0) -> SIPDialog::FINAL(28) 10:09:18 4052541233mS RES: Mon 13/3/2017 10:09:18 FreeMem=53736460 Heap=52822356(0) Cache=914104 MemObjs=12132(18126) CMMsg=8(10) ASN=0 Buff=5200 1376 1000 7351 5 Links=56010(56365) BTree=808(2106) CPU=02.86% CPUStats=03.11%/1/4/1163/13758/14978/00.00%/1 /02.68% MCR=0 MCW=0 10:09:18 4052541233mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=55 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=67 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=0 TCP=205(TLS=91) TAPI=1 Partner=25 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034 10:09:18 4052541233mS RES4: XML MemObjs=63 PoolMem=4748404(2) FreePoolMem=4733100(0) 10:09:18 4052541233mS RES5: CLog MemObjs=519 FreePoolMem(Objs)=4212(81) TotalMem=198150 10:09:21 4052544432mS H323Evt: Recv: RegistrationRequest 172.30.22.101; Extn(3500), time since last RRQ-KA 55060, Endpoints registered: 3; Endpoints in registration: 0 10:09:21 4052544957mS SIP Rx: UDP 10.1.10.150:5060 -> 10.1.10.20:5060 OPTIONS sip:sip0000001_aciaegis@10.1.10.20:5060 SIP/2.0 Via: SIP/2.0/UDP 10.1.10.150:5060;branch=z9hG4bK166562700 From: "NOCALLERID" ;tag=3az08zUpSS.4Bopx56D83396C613a2a4 To: Call-ID: 472497898@10.1.10.150 CSeq: 51842 OPTIONS Contact: Supported: 100rel Max-Forwards: 70 User-Agent: ewb2bua/14.7.2 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, UPDATE Content-Length: 0 10:09:21 4052544959mS Sip: Association found trunk: SIP Line (17) 10:09:21 4052544959mS Sip: SIPDialog f173a4f4 created, dialogs 3 txn_keys 5 10:09:21 4052544960mS Sip: SIPDialog::ExtractResponseParamsFromViaHeader remote sent_by: 10.1.10.150:5060 trunk 10:09:21 4052544960mS Sip: SIPDialog::ExtractResponseParamsFromViaHeader remote sent by transport: SIP/2.0/UDP trunk 10:09:21 4052544961mS Sip: (f173a4f4) SendSIPResponse: OPTIONS code 503 SENT TO 10.1.10.150 5060 10:09:21 4052544961mS SIP Tx: UDP 10.1.10.20:5060 -> 10.1.10.150:5060 SIP/2.0 503 Service Unavailable Via: SIP/2.0/UDP 10.1.10.150:5060;branch=z9hG4bK166562700 From: "NOCALLERID" ;tag=3az08zUpSS.4Bopx56D83396C613a2a4 Call-ID: 472497898@10.1.10.150 CSeq: 51842 OPTIONS Supported: timer Server: IP Office 9.1.6.0 build 153 To: ;tag=961eadc0b38cd781 Content-Length: 0 10:09:21 4052544962mS Sip: (f173a4f4) UpdateSIPCallState SIPDialog::INITIAL(0) -> SIPDialog::FINAL(28) 10:09:22 4052546020mS Sip: sip_indicateTimeOut Timer 11 10:09:22 4052546020mS Sip: Timer 11 callback found dialog f1845ee8 4c9f060bf1dc708db91b631ac80f19fe OPTIONS SIPDialog::FINAL 10:09:22 4052546020mS Sip: Completed ... (todelete) removing/preserving Dialog f1845ee8 of CallId: 4c9f060bf1dc708db91b631ac80f19fe and State: SIPDialog::FINAL(28) 10:09:22 4052546020mS Sip: SIPDialog f1845ee8 deleted, dialogs 2 txn_keys 4 10:09:22 4052546021mS Sip: sip_indicateTimeOut txn_keys 4 10:09:22 4052546234mS RES: Mon 13/3/2017 10:09:23 FreeMem=53737000 Heap=52822356(1) Cache=914644 MemObjs=12118(18126) CMMsg=8(10) ASN=0 Buff=5200 1376 1000 7351 5 Links=56010(56365) BTree=808(2106) CPU=02.93% CPUStats=03.29%/5/9/1163/13612/14978/00.00%/1 /02.68% MCR=0 MCW=0 10:09:22 4052546234mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=55 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=67 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=0 TCP=205(TLS=91) TAPI=1 Partner=25 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034 10:09:22 4052546234mS RES4: XML MemObjs=63 PoolMem=4748404(2) FreePoolMem=4733100(0) 10:09:22 4052546234mS RES5: CLog MemObjs=519 FreePoolMem(Objs)=4212(81) TotalMem=198150 10:09:22 4052546794mS SIP Tx: UDP 10.1.10.20:5060 -> 10.1.10.150:5060 REGISTER sip:10.1.10.150 SIP/2.0 Via: SIP/2.0/UDP 10.1.10.20:5060;rport;branch=z9hG4bK6a7c2ef8c69525cb6ff57231a251302b From: ;tag=b5721b6d62fd540c To: Call-ID: 3cc724274f214f0986cf86c3df86a65f CSeq: 1228661098 REGISTER Contact: Expires: 3600 Authorization: Digest username="sip0000001_aciaegis",realm="fe-4a2b-6w.coredial.com",nonce="5399b228",response="5d4f032c9fb05e3aad1f11063f2d207e",uri="sip:10.1.10.150" Max-Forwards: 70 User-Agent: IP Office 9.1.6.0 build 153 Supported: timer Content-Length: 0 10:09:25 4052549961mS Sip: sip_indicateTimeOut Timer 10 10:09:25 4052549961mS Sip: Timer 10 callback found dialog f173a4f4 472497898@10.1.10.150 OPTIONS SIPDialog::FINAL 10:09:25 4052549961mS Sip: Completed f173a4f4 ... removing Dialog of CallId 472497898@10.1.10.150 and State: SIPDialog::FINAL(28) 10:09:25 4052549961mS Sip: SIPDialog f173a4f4 deleted, dialogs 1 txn_keys 3 10:09:25 4052549962mS Sip: sip_indicateTimeOut txn_keys 3 10:09:33 4052557731mS H323Evt: Recv: RegistrationRequest 172.30.22.100; Extn(3511), time since last RRQ-KA 55015, Endpoints registered: 3; Endpoints in registration: 0 10:09:39 4052562794mS SIP Tx: UDP 10.1.10.20:5060 -> 10.1.10.150:5060 REGISTER sip:10.1.10.150 SIP/2.0 Via: SIP/2.0/UDP 10.1.10.20:5060;rport;branch=z9hG4bK6a7c2ef8c69525cb6ff57231a251302b From: ;tag=b5721b6d62fd540c To: Call-ID: 3cc724274f214f0986cf86c3df86a65f CSeq: 1228661098 REGISTER Contact: Expires: 3600 Authorization: Digest username="sip0000001_aciaegis",realm="fe-4a2b-6w.coredial.com",nonce="5399b228",response="5d4f032c9fb05e3aad1f11063f2d207e",uri="sip:10.1.10.150" Max-Forwards: 70 User-Agent: IP Office 9.1.6.0 build 153 Supported: timer Content-Length: 0 10:09:40 4052563441mS CMExtnEvt: Lynn Lohmann: No user activity 10:09:41 4052564794mS Sip: sip_indicateTimeOut Timer 6 10:09:41 4052564794mS Sip: Timer 6 callback found dialog f17c1fa4 3cc724274f214f0986cf86c3df86a65f REGISTER SIPDialog::INITIAL 10:09:41 4052564794mS Sip: Completed ... (todelete) removing/preserving Dialog f17c1fa4 of CallId: 3cc724274f214f0986cf86c3df86a65f and State: SIPDialog::INITIAL(0) 10:09:41 4052564794mS PRN: SIP Line (17) parameter sip0000001_aciaegis registration has failed, setting backoff retry timer to 960 secs 10:09:41 4052564795mS Sip: SIPDialog f17c1fa4 deleted, dialogs 0 txn_keys 2 10:09:41 4052564795mS CMCallEvt: ac1e14440001d7df 0.120799.0 -1 SIPTrunk Endpoint: StateChange: END=X CMCSIdle->CMCSDelete 10:09:41 4052564795mS Sip: ~SipTrunkEndpoint ac1e14440001d7df 0.120799.0 -1 SIPTrunk Endpoint 10:09:41 4052564795mS CMCallEvt: ac1e14440001d7df 0.120799.0 -1 BaseEP: DELETE CMEndpoint f17c3850 TOTAL NOW=2 CALL_LIST=1 10:09:41 4052564796mS Sip: sip_indicateTimeOut txn_keys 2 10:09:41 4052565235mS RES: Mon 13/3/2017 10:09:41 FreeMem=53832072 Heap=52887932(1) Cache=944140 MemObjs=11914(18126) CMMsg=8(10) ASN=0 Buff=5200 1376 1000 7350 5 Links=56001(56365) BTree=808(2106) CPU=03.52% CPUStats=02.83%/1/4/1163/13691/14978/00.00%/0 /02.69% MCR=0 MCW=0 10:09:41 4052565236mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=55 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=65 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=0 TCP=205(TLS=91) TAPI=1 Partner=25 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034 10:09:41 4052565236mS RES4: XML MemObjs=63 PoolMem=4748404(2) FreePoolMem=4733100(0) 10:09:41 4052565236mS RES5: CLog MemObjs=519 FreePoolMem(Objs)=4212(81) TotalMem=198150 10:09:47 4052570975mS H323Evt: Recv: RegistrationRequest 172.30.22.102; Extn(3501), time since last RRQ-KA 55014, Endpoints registered: 3; Endpoints in registration: 0 10:09:49 4052572736mS RES: Mon 13/3/2017 10:09:49 FreeMem=53833252 Heap=52889544(1) Cache=943708 MemObjs=11910(18126) CMMsg=8(10) ASN=0 Buff=5200 1375 1000 7351 5 Links=56000(56365) BTree=808(2106) CPU=03.67% CPUStats=03.66%/2/5/1163/13511/14978/00.01%/1 /02.72% MCR=0 MCW=0 10:09:49 4052572736mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=55 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=64 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=0 TCP=204(TLS=91) TAPI=1 Partner=25 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034 10:09:49 4052572736mS RES4: XML MemObjs=63 PoolMem=4748404(2) FreePoolMem=4733100(0) 10:09:49 4052572736mS RES5: CLog MemObjs=519 FreePoolMem(Objs)=4212(81) TotalMem=198150 10:09:58 4052581994mS PRN: Optimizing BTree Lists Completed...Started:4052581993 Duration:1 Size:131 Attempted:131 ********** SysMonitor v9.1.8.0 build 172 [connected to 172.30.20.68 (ICUCarlosGabado)] ********** 10:09:59 4052582053mS PRN: Monitor Status IP 500 V2 9.1.6.0 build 153 10:09:59 4052582053mS PRN: LAW=U PRI=1, BRI=0, ALOG=8, VCOMP=20, MDM=0, WAN=0, MODU=0 LANM=0 CkSRC=9 VMAIL=1(VER=3 TYP=1) 1-X=1 CALLS=1(TOT=2260) 10:10:15 4052599485mS H323Evt: Recv: RegistrationRequest 172.30.22.101; Extn(3500), time since last RRQ-KA 55053, Endpoints registered: 3; Endpoints in registration: 0 10:10:22 4052605174mS SIP Rx: UDP 10.1.10.150:5060 -> 10.1.10.20:5060 OPTIONS sip:sip0000001_aciaegis@10.1.10.20:5060 SIP/2.0 Via: SIP/2.0/UDP 10.1.10.150:5060;branch=z9hG4bK745293046 From: "NOCALLERID" ;tag=3az08zUpSS.4Bopx52A62A6FC69a2348 To: Call-ID: 2128471163@10.1.10.150 CSeq: 51843 OPTIONS Contact: Supported: 100rel Max-Forwards: 70 User-Agent: ewb2bua/14.7.2 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, UPDATE Content-Length: 0 10:10:22 4052605176mS Sip: Association found trunk: SIP Line (17) 10:10:22 4052605176mS Sip: SIPDialog f173a4f4 created, dialogs 1 txn_keys 3 10:10:22 4052605177mS Sip: SIPDialog::ExtractResponseParamsFromViaHeader remote sent_by: 10.1.10.150:5060 trunk 10:10:22 4052605177mS Sip: SIPDialog::ExtractResponseParamsFromViaHeader remote sent by transport: SIP/2.0/UDP trunk 10:10:22 4052605178mS Sip: (f173a4f4) SendSIPResponse: OPTIONS code 503 SENT TO 10.1.10.150 5060 10:10:22 4052605178mS SIP Tx: UDP 10.1.10.20:5060 -> 10.1.10.150:5060 SIP/2.0 503 Service Unavailable Via: SIP/2.0/UDP 10.1.10.150:5060;branch=z9hG4bK745293046 From: "NOCALLERID" ;tag=3az08zUpSS.4Bopx52A62A6FC69a2348 Call-ID: 2128471163@10.1.10.150 CSeq: 51843 OPTIONS Supported: timer Server: IP Office 9.1.6.0 build 153 To: ;tag=d81e7b9b6664163c Content-Length: 0 10:10:22 4052605179mS Sip: (f173a4f4) UpdateSIPCallState SIPDialog::INITIAL(0) -> SIPDialog::FINAL(28) 10:10:21 4052605251mS RES: Mon 13/3/2017 10:10:21 FreeMem=53790192 Heap=52856756(1) Cache=933436 MemObjs=11991(18126) CMMsg=8(10) ASN=0 Buff=5200 1376 1000 7350 5 Links=56004(56365) BTree=808(2106) CPU=03.11% CPUStats=02.93%/2/5/1163/13500/14978/00.01%/1 /02.72% MCR=0 MCW=0 10:10:21 4052605251mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=55 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=63 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=0 TCP=204(TLS=91) TAPI=1 Partner=25 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034 10:10:21 4052605251mS RES4: XML MemObjs=63 PoolMem=4748404(2) FreePoolMem=4733100(0) 10:10:21 4052605252mS RES5: CLog MemObjs=519 FreePoolMem(Objs)=4212(81) TotalMem=198150 10:10:24 4052608376mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,3411: Digit Key Pressed 9 10:10:24 4052608378mS CMCallEvt: 0000000000000000 0.120801.0 -1 BaseEP: NEW CMEndpoint f17fe4b8 TOTAL NOW=3 CALL_LIST=1 10:10:24 4052608378mS CMCallEvt: 0000000000000000 0.120801.0 -1 Darrell Maier.-1: NEW CMExtnEndpoint f17fe4b8, Name=Darrell Maier, Extn=3411, Phys Extn=3411 10:10:24 4052608378mS CMCallEvt: CREATE CALL:2261 (f177e6f0) 10:10:24 4052608378mS CMCallEvt: 0000000000000000 0.120802.0 -1 BaseEP: NEW CMEndpoint f1819a68 TOTAL NOW=4 CALL_LIST=1 10:10:24 4052608380mS CMExtnEvt: Darrell Maier: CMExtnHandler::SetCurrent( id: 0->120801 ) 10:10:24 4052608380mS CMCallEvt: ac1e14440001d7e1 0.120801.0 2261 Darrell Maier.0: StateChange: END=A CMCSIdle->CMCSDialInitiated 10:10:24 4052608380mS CMExtnEvt: v=3 State, new=Dialling old=Idle,0,0,Darrell Maier 10:10:24 4052608381mS CMTARGET: ac1e14440001d7e1 0.120801.0 2261 Darrell Maier.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party= sub= calling=3411 calling_sub= dir=out complete=0 ses=0 10:10:24 4052608381mS CMTARGET: ac1e14440001d7e1 0.120801.0 2261 Darrell Maier.0: ADD TARGET (N): number= type=100 depth=1 nobar=1 setorig=1 ses=0 10:10:24 4052608381mS CMCallEvt: ac1e14440001d7e1 0.120801.0 2261 Darrell Maier.0: StateChange: END=A CMCSDialInitiated->CMCSDialling 10:10:24 4052608383mS CMTARGET: ac1e14440001d7e1 0.120801.0 2261 Darrell Maier.0: Setting Hard Timer 4000 10:10:24 4052608383mS CMTARGET: ac1e14440001d7e1 0.120801.0 2261 Darrell Maier.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=9 sub= calling=3411 calling_sub= dir=out complete=0 ses=0 10:10:24 4052608383mS CMTARGET: ac1e14440001d7e1 0.120801.0 2261 Darrell Maier.0: ADD TARGET (N): number=9 type=100 depth=1 nobar=1 setorig=1 ses=0 10:10:24 4052608383mS CMTARGET: ac1e14440001d7e1 0.120801.0 2261 Darrell Maier.0: SYS SC: 9 2 sc=type=Dial code=9N, num=N callinfop->sending_complete=0 secondary_dialtone= 10:10:24 4052608384mS CMARS: FindActiveARSByGroupID GroupID=52 - Found 10:10:24 4052608384mS CMARS: MakeCallTarget - Called Number: 10:10:24 4052608384mS CMCallEvt: 0000000000000000 0.120803.0 -1 BaseEP: NEW CMEndpoint f1687d40 TOTAL NOW=5 CALL_LIST=2 10:10:24 4052608385mS CMTARGET: ac1e14440001d7e1 0.120801.0 2261 Darrell Maier.0: CancelTimer CMTCDelayedProcessing 10:10:24 4052608385mS CMTARGET: ac1e14440001d7e1 0.120801.0 2261 Darrell Maier.0: INITIAL TARGETING SUCCEEDED 10:10:24 4052608385mS CMTARGET: ac1e14440001d7e1 0.120801.0 2261 Darrell Maier.0: GetNoAnswerTimer:20 10:10:24 4052608386mS CMCallEvt: 0000000000000000 0.120802.0 2261 TargetingEP: StateChange: END=B CMCSIdle->CMCSOffering 10:10:24 4052608386mS CMCallEvt: 0000000000000000 0.120803.0 2261 ARS for SIP Trunk: StateChange: END=T CMCSIdle->CMCSOffering 10:10:24 4052608387mS CMCallEvt: 0000000000000000 0.120802.0 2261 TargetingEP: RequestEnd 0000000000000000 0.120803.0 2261 ARS for SIP Trunk 10:10:24 4052608387mS CMTARGET: ac1e14440001d7e1 0.120801.0 2261 Darrell Maier.0: CancelTimer CMTCNoAnswerTimeout 10:10:24 4052608387mS CMCallEvt: 0000000000000000 0.120803.0 2261 ARS for SIP Trunk: StateChange: END=B CMCSOffering->CMCSOverlapRecv 10:10:24 4052608388mS CMARS: FORM: SIP Trunk - Received Number: 10:10:24 4052608388mS CMARS: CMARSTargetingPending 10:10:24 4052608388mS CMCallEvt: 0000000000000000 0.120802.0 -1 TargetingEP: StateChange: END=X CMCSOffering->CMCSDelete 10:10:24 4052608388mS CMCallEvt: 0000000000000000 0.120802.0 -1 BaseEP: DELETE CMEndpoint f1819a68 TOTAL NOW=4 CALL_LIST=2 10:10:24 4052608389mS CD: CALL: 0.120801.0 BState=Idle Cut=2 Music=3.0 Aend="Darrell Maier(3411)" (2.9) Bend="" [] (0.0) CalledNum=9 () CallingNum=3411 (Darrell Maier) Internal=1 Time=11 AState=Dialling 10:10:24 4052608392mS CMMap: a=2.9 b=0.0 D1 10:10:24 4052608731mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,3411: Digit Key Pressed 1 10:10:24 4052608732mS CMARS: FORM: SIP Trunk - Received Number: 1 10:10:24 4052608732mS CMARS: CMARSTargetingPending 10:10:24 4052608734mS CMMap: a=2.9 b=0.0 D0 10:10:24 4052608981mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,3411: Digit Key Pressed 5 10:10:24 4052608982mS CMARS: FORM: SIP Trunk - Received Number: 15 10:10:24 4052608982mS CMARS: CMARSTargetingPending 10:10:25 4052609147mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,3411: Digit Key Pressed 8 10:10:25 4052609148mS CMARS: FORM: SIP Trunk - Received Number: 158 10:10:25 4052609148mS CMARS: CMARSTargetingPending 10:10:25 4052609344mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,3411: Digit Key Pressed 6 10:10:25 4052609344mS CMARS: FORM: SIP Trunk - Received Number: 1586 10:10:25 4052609345mS CMARS: CMARSTargetingPending 10:10:25 4052609544mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,3411: Digit Key Pressed 4 10:10:25 4052609545mS CMARS: FORM: SIP Trunk - Received Number: 15864 10:10:25 4052609545mS CMARS: CMARSTargetingPending 10:10:25 4052609779mS CMCallEvt: 0000000000000000 0.120804.0 -1 BaseEP: NEW CMEndpoint f1839938 TOTAL NOW=5 CALL_LIST=2 10:10:25 4052609779mS CMCallEvt: 0000000000000000 0.120804.0 -1 Craig Albertson.-1: NEW CMExtnEndpoint f1839938, Name=Craig Albertson, Extn=3400, Phys Extn=3400 10:10:25 4052609780mS CMCallEvt: CREATE CALL:2262 (f1808c40) 10:10:25 4052609780mS CMCallEvt: 0000000000000000 0.120805.0 -1 BaseEP: NEW CMEndpoint f1819a68 TOTAL NOW=6 CALL_LIST=2 10:10:25 4052609781mS CMExtnEvt: Craig Albertson: CMExtnHandler::SetCurrent( id: 0->120804 ) 10:10:25 4052609782mS CMCallEvt: ac1e14440001d7e4 0.120804.0 2262 Craig Albertson.0: StateChange: END=A CMCSIdle->CMCSDialInitiated 10:10:25 4052609782mS CMExtnEvt: v=1 State, new=Dialling old=Idle,0,0,Craig Albertson 10:10:25 4052609783mS CMTARGET: ac1e14440001d7e4 0.120804.0 2262 Craig Albertson.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party= sub= calling=3400 calling_sub= dir=out complete=0 ses=0 10:10:25 4052609783mS CMTARGET: ac1e14440001d7e4 0.120804.0 2262 Craig Albertson.0: ADD TARGET (N): number= type=100 depth=1 nobar=1 setorig=1 ses=0 10:10:25 4052609783mS CMCallEvt: ac1e14440001d7e4 0.120804.0 2262 Craig Albertson.0: StateChange: END=A CMCSDialInitiated->CMCSDialling 10:10:25 4052609785mS CD: CALL: 0.120804.0 BState=Idle Cut=1 Music=3.0 Aend="Craig Albertson(3400)" (0.1) Bend="" [] (0.0) CalledNum= () CallingNum=3400 (Craig Albertson) Internal=1 Time=5 AState=DialInitiated 10:10:25 4052609787mS CMMap: a=0.1 b=0.0 D1 10:10:25 4052609788mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,3411: Digit Key Pressed 8 10:10:25 4052609788mS CMARS: FORM: SIP Trunk - Received Number: 158648 10:10:25 4052609788mS CMARS: CMARSTargetingPending 10:10:25 4052609906mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,3411: Digit Key Pressed 8 10:10:25 4052609906mS CMARS: FORM: SIP Trunk - Received Number: 1586488 10:10:25 4052609907mS CMARS: CMARSTargetingPending 10:10:26 4052610081mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,3411: Digit Key Pressed 5 10:10:26 4052610082mS CMARS: FORM: SIP Trunk - Received Number: 15864885 10:10:26 4052610082mS CMARS: CMARSTargetingPending 10:10:26 4052610178mS Sip: sip_indicateTimeOut Timer 10 10:10:26 4052610178mS Sip: Timer 10 callback found dialog f173a4f4 2128471163@10.1.10.150 OPTIONS SIPDialog::FINAL 10:10:26 4052610178mS Sip: Completed f173a4f4 ... removing Dialog of CallId 2128471163@10.1.10.150 and State: SIPDialog::FINAL(28) 10:10:26 4052610178mS Sip: SIPDialog f173a4f4 deleted, dialogs 0 txn_keys 2 10:10:26 4052610179mS Sip: sip_indicateTimeOut txn_keys 2 10:10:27 4052610255mS RES: Mon 13/3/2017 10:10:27 FreeMem=53770984 Heap=52889356(2) Cache=881628 MemObjs=11961(18126) CMMsg=8(10) ASN=0 Buff=5200 1374 1000 7350 5 Links=56014(56365) BTree=814(2106) CPU=03.42% CPUStats=05.21%/1/6/1163/13258/14978/00.03%/1 /02.77% MCR=0 MCW=0 10:10:27 4052610255mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=55 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=69 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=0 TCP=204(TLS=91) TAPI=1 Partner=25 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034 10:10:27 4052610256mS RES4: XML MemObjs=63 PoolMem=4748404(2) FreePoolMem=4733100(0) 10:10:27 4052610256mS RES5: CLog MemObjs=519 FreePoolMem(Objs)=4212(81) TotalMem=198150 10:10:27 4052610320mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,3411: Digit Key Pressed 4 10:10:27 4052610321mS CMARS: FORM: SIP Trunk - Received Number: 158648854 10:10:27 4052610321mS CMARS: CMARSTargetingPending 10:10:27 4052610446mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,3411: Digit Key Pressed 4 10:10:27 4052610447mS CMARS: FORM: SIP Trunk - Received Number: 1586488544 10:10:27 4052610447mS CMARS: CMARSTargetingPending 10:10:27 4052610460mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,3400: Menu Key Pressed 20:App05 10:10:27 4052610460mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,3400: DSS Key Pressed 5 10:10:27 4052610461mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,Craig Albertson: DSS Emulation DefinityCPark Key Pressed 4 10:10:27 4052610660mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,3411: Digit Key Pressed 0 10:10:27 4052610661mS CMARS: FORM: SIP Trunk - Received Number: 15864885440 10:10:27 4052610661mS CMARS: CMARSTargetingPending 10:10:28 4052611353mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,3400: Menu Key Pressed 4:A 10:10:28 4052611353mS CMExtnEvt: Craig Albertson: ProcessShortCode feature=UnParkCall id=1 10:10:28 4052611353mS CMExtnEvt: Craig Albertson: UnParkCall pickup=ac1e14440001d7e0 0.120800.0 2260 PARK:1 OnCurrent=1 10:10:28 4052611353mS CMCallEvt: ac1e14440001d7e4 0.120804.0 2262 Craig Albertson.0: Pickup ac1e14440001d7e0 0.120800.0 2260 PARK:1 state CMCSDialling 10:10:28 4052611354mS CMLOGGING: CALL:2017/03/1310:10,00:00:00,000,,O,,,,,,1,,"",0,n/a 10:10:28 4052611354mS CD: CALL: 0.120804.0 BState=Idle Cut=1 Music=0.0 Aend="" (0.0) Bend="" [] (0.0) CalledNum= () CallingNum= () Internal=1 Time=1574 AState=Idle 10:10:28 4052611355mS CD: CALL: 0.120804.0 Deleted 10:10:28 4052611355mS CMCallEvt: 0000000000000000 0.120805.0 -1 BaseEP: DELETE CMEndpoint f1819a68 TOTAL NOW=5 CALL_LIST=2 10:10:28 4052611355mS CMCallEvt: END CALL:2262 (f1808c40) 10:10:28 4052611356mS CMCallEvt: ac1e14440001d7e4 0.120804.0 -1 Craig Albertson.0: StateChange: END=X CMCSDialling->CMCSOGConnReq 10:10:28 4052611356mS CMExtnEvt: v=1 State, new=Connected old=Dialling,0,0,Craig Albertson 10:10:28 4052611358mS CMCallEvt: ac1e14440001d7e4 0.120804.0 -1 Craig Albertson.0: PickupProcessInboundMsg CMConnectAck 10:10:28 4052611358mS CMCallEvt: ac1e14440001d7e4 0.120804.0 -1 Craig Albertson.0: Pickup Complete 10:10:28 4052611358mS PRN: CDR - ResetQueueSize=500 10:10:28 4052611359mS PRN: CDR - TCPSend maxqueuesize=500 framecount=500 operational=0 10:10:28 4052611359mS ERR: CDRServer discarding - framecount=500 10:10:28 4052611359mS CMCallEvt: 3400: Pickup Complete CALL: (AEND=913133788143 BEND=1) ss_pickup 0 10:10:28 4052611359mS CMCallEvt: ac1e14440001d7e0 0.120800.0 2260 PARK:1: CallLost (Park @1) cause=CMCausePickup 10:10:28 4052611361mS CMCallEvt: ac1e14440001d7e0 0.120800.0 -1 PARK:1: StateChange: END=X CMCSConnected->CMCSDelete 10:10:28 4052611363mS CMCallEvt: ac1e14440001d7e4 0.120804.0 2260 Craig Albertson.0: StateChange: END=B CMCSOGConnReq->CMCSConnected 10:10:28 4052611363mS CMTARGET: ac1e14440001d7e4 0.120804.0 2260 Craig Albertson.0: ~CMTargetHandler f17923cc ep f1839938 10:10:28 4052611366mS CMCallEvt: ac1e14440001d7e0 0.120800.0 -1 BaseEP: DELETE CMEndpoint f1805bcc TOTAL NOW=4 CALL_LIST=2 10:10:28 4052611366mS CD: CALL: 9.18.1 BState=Connected Cut=3 Music=0.0 Aend="Line 9" (5.7) Bend="" [Craig Albertson(3400)] (0.1) CalledNum=3400 (Craig Albertson) CallingNum=913133788143 (Cell Phone MI) Internal=0 Time=146856 AState=Connected 10:10:28 4052611368mS CMMap: a=0.1 b=0.0 D0 10:10:28 4052611368mS CMMap: PCG::MapBChan pcp[116]b1r0 cp_b f4f39708 other_cp_b 0 type CGTypeSimple 10:10:28 4052611368mS CMMap: a=5.7 b=0.0 H0 10:10:28 4052611368mS CMMap: PCG::MapBChan pcp[91]b1r0 cp_b f55ca8f4 other_cp_b f4f39708 type CGTypeSimple 10:10:28 4052611368mS CMMap: a=0.1 b=5.7 M12 10:10:29 4052612749mS H323Evt: Recv: RegistrationRequest 172.30.22.100; Extn(3511), time since last RRQ-KA 55018, Endpoints registered: 3; Endpoints in registration: 0 10:10:31 4052615384mS CMARS: Case 1 - dial_delay_time: 4000 has expired - Resolve what we might have - Called Number: 15864885440 Addr: f1687d40 10:10:31 4052615384mS CMARS: FORM: SIP Trunk - Received Number: 15864885440 10:10:31 4052615385mS CMARS: FOUND A SHORT CODE - short_code: 1N; - Tel: 1NSi5862262080 - Called_Party: 15864885440 - Line Group Id: 17 10:10:31 4052615385mS CMARS: SetCurrentTarget: Short_Code: 1N; - Line_Group_ID: 17 10:10:31 4052615385mS CMARS: FindActiveARSByGroupID GroupID=17 - Not Found 10:10:31 4052615385mS CMLRQ: FindActiveLRQByGroupID GroupID=17 - Not Found 10:10:31 4052615385mS CMTARGET: Group Id: 17 has NOT been found in Line: 9 10:10:31 4052615385mS CMTARGET: Problem with Line Id: 17 - check_DNS 1 OperationalTest: 0, IP address: 10.1.10.150 10:10:31 4052615386mS CMARS: LINE with group ID: 17 HAS NO CHANNEL: 34 - ATTEMPT OTHER TARGETS 10:10:31 4052615386mS CMARS: ModifyCMARSTarget: Short_Code: 1N; - Line_Group_ID: 17 set line status to CMARS_OUTOFSERVICE 10:10:31 4052615386mS CMTARGET: Group Id: 17 has NOT been found in Line: 9 10:10:31 4052615386mS CMTARGET: Problem with Line Id: 17 - check_DNS 1 OperationalTest: 0, IP address: 10.1.10.150 10:10:31 4052615386mS CMARS: No Alternate ARS Or User Priority lower than ARS Priority - Remain on the Current Form: SIP Trunk 10:10:31 4052615386mS CMARS: CMARSTargetingBusy 10:10:31 4052615387mS CMCallEvt: ac1e14440001d7e1 0.120803.0 2261 ARS for SIP Trunk: StateChange: END=B CMCSOverlapRecv->CMCSAccept 10:10:31 4052615387mS CMCallEvt: ac1e14440001d7e1 0.120801.0 2261 Darrell Maier.0: StateChange: END=A CMCSDialling->CMCSRingBack 10:10:31 4052615387mS CMExtnEvt: v=3 State, new=Alerting old=Dialling,0,0,Darrell Maier 10:10:31 4052615388mS CD: CALL: 0.120801.0 BState=Ringing Cut=3 Music=0.0 Aend="Darrell Maier(3411)" (2.9) Bend="" [] (0.0) CalledNum=915864885440 () CallingNum=3411 (Darrell Maier) Internal=1 Time=7010 AState=Ringing 10:10:31 4052615391mS CMMap: a=21.42 b=0.0 DTMF::AllocateRAS allocated CMRTVoicemail(f561ade4) resource busy 1, total 45 10:10:31 4052615391mS CMMap: a=21.42 b=1.65535 T 10:10:31 4052615391mS CMMap: PCG::MapBChan pcp[114]b1r0 cp_b f4f3cb88 other_cp_b f561accc type CGTypeDTMF 10:10:31 4052615391mS CMMap: a=21.42 b=2.9 M22 10:10:31 4052615391mS CMMap: DTMF::PlayTones g T[584] Tones ',EEEEE' 10:10:31 4052615391mS CMMap: Started playing tones, cp[114]b1r0 (from g null) 10:10:31 4052615391mS CMMap: cp[114]b1r0 SetOperGroup2 from g null to g null not executed, playing tones in progress ,EEEEE 10:10:31 4052615770mS RES: Mon 13/3/2017 10:10:33 FreeMem=53794328 Heap=52888788(1) Cache=905540 MemObjs=11966(18126) CMMsg=8(10) ASN=0 Buff=5200 1373 1000 7351 5 Links=56021(56365) BTree=814(2106) CPU=03.92% CPUStats=05.40%/5/12/1163/13257/14978/00.03%/ 1/02.74% MCR=0 MCW=0 10:10:31 4052615771mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=55 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=69 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=0 TCP=205(TLS=91) TAPI=1 Partner=25 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034 10:10:31 4052615771mS RES4: XML MemObjs=63 PoolMem=4748404(2) FreePoolMem=4733100(0) 10:10:31 4052615771mS RES5: CLog MemObjs=519 FreePoolMem(Objs)=4212(81) TotalMem=198150 10:10:32 4052616384mS CMARS: Retarget existing BUSY targets - Num of Busy Targets: 1 - Current Form: SIP Trunk 10:10:33 4052617212mS CMMap: PCG::UnmapBChan pcp[114]b1r0 cp_b f4f3cb88 other_cp_b f561accc 10:10:33 4052617212mS CMMap: a=21.42 b=2.9 M02 10:10:33 4052617212mS CMMap: a=21.42 b=0.0 T0 10:10:33 4052617214mS CMMap: a=21.42 b=0.0 DTMF::~DTMF freed CMRTUnknown(f561ade4) resource busy 0, total 45 10:10:33 4052617215mS CMMap: a=21.42 b=0.0 DTMF::AllocateRAS allocated CMRTVoicemail(f561ade4) resource busy 1, total 45 10:10:33 4052617215mS CMMap: a=21.42 b=1.65535 T 10:10:33 4052617215mS CMMap: PCG::MapBChan pcp[114]b1r0 cp_b f4f3cb88 other_cp_b f561accc type CGTypeDTMF 10:10:33 4052617215mS CMMap: a=21.42 b=2.9 M22 10:10:33 4052617215mS CMMap: DTMF::PlayTones g T[585] Tones ',EEEEE' 10:10:33 4052617215mS CMMap: Started playing tones, cp[114]b1r0 (from g null) 10:10:33 4052617215mS CMMap: cp[114]b1r0 SetOperGroup2 from g null to g null not executed, playing tones in progress ,EEEEE 10:10:35 4052619036mS CMMap: PCG::UnmapBChan pcp[114]b1r0 cp_b f4f3cb88 other_cp_b f561accc 10:10:35 4052619036mS CMMap: a=21.42 b=2.9 M02 10:10:35 4052619036mS CMMap: a=21.42 b=0.0 T0 10:10:35 4052619037mS CMMap: a=21.42 b=0.0 DTMF::~DTMF freed CMRTUnknown(f561ade4) resource busy 0, total 45 10:10:39 4052622384mS CMARS: Retarget existing BUSY targets - Num of Busy Targets: 1 - Current Form: SIP Trunk 10:10:39 4052622386mS CMMap: a=21.42 b=0.0 DTMF::AllocateRAS allocated CMRTVoicemail(f561ade4) resource busy 1, total 45 10:10:39 4052622386mS CMMap: a=21.42 b=1.65535 T 10:10:39 4052622386mS CMMap: PCG::MapBChan pcp[114]b1r0 cp_b f4f3cb88 other_cp_b f561accc type CGTypeDTMF 10:10:39 4052622386mS CMMap: a=21.42 b=2.9 M22 10:10:39 4052622386mS CMMap: DTMF::PlayTones g T[586] Tones ',EEEEE' 10:10:39 4052622386mS CMMap: Started playing tones, cp[114]b1r0 (from g null) 10:10:39 4052622386mS CMMap: cp[114]b1r0 SetOperGroup2 from g null to g null not executed, playing tones in progress ,EEEEE 10:10:39 4052622773mS RES: Mon 13/3/2017 10:10:40 FreeMem=53794328 Heap=52888788(1) Cache=905540 MemObjs=11966(18126) CMMsg=8(10) ASN=0 Buff=5200 1372 1000 7351 5 Links=56021(56365) BTree=814(2106) CPU=04.22% CPUStats=04.30%/2/6/1163/13429/14978/00.00%/1 /02.71% MCR=0 MCW=0 10:10:39 4052622774mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=55 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=68 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=0 TCP=205(TLS=91) TAPI=1 Partner=25 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034 10:10:39 4052622774mS RES4: XML MemObjs=63 PoolMem=4748404(2) FreePoolMem=4733100(0) 10:10:39 4052622774mS RES5: CLog MemObjs=519 FreePoolMem(Objs)=4212(81) TotalMem=198150 10:10:41 4052624207mS CMMap: PCG::UnmapBChan pcp[114]b1r0 cp_b f4f3cb88 other_cp_b f561accc 10:10:41 4052624207mS CMMap: a=21.42 b=2.9 M02 10:10:41 4052624207mS CMMap: a=21.42 b=0.0 T0 10:10:41 4052624208mS CMMap: a=21.42 b=0.0 DTMF::~DTMF freed CMRTUnknown(f561ade4) resource busy 0, total 45 10:10:41 4052624363mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,3411: Menu Key Pressed 12:I 10:10:41 4052624364mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,3411: Feature Key Pressed 6:DCPLFeatureDrop 10:10:41 4052624364mS CMCallEvt: ac1e14440001d7e1 0.120801.0 2261 Darrell Maier.0: StateChange: END=A CMCSRingBack->CMCSCompleted 10:10:41 4052624365mS CMExtnEvt: v=3 State, new=PortRecoverDelay old=Alerting,0,0,Darrell Maier 10:10:41 4052624366mS PRN: CDR - TCPSend maxqueuesize=500 framecount=500 operational=0 10:10:41 4052624367mS CMLOGGING: CALL:2017/03/1310:10,00:00:00,000,3411,O,915864885440,915864885440,DarrellMaier,,,1,,"",0,n/a 10:10:41 4052624367mS CD: CALL: 0.120801.0 BState=Ringing Cut=2 Music=0.0 Aend="Darrell Maier(3411)" (2.9) Bend="" [] (0.0) CalledNum=915864885440 () CallingNum=3411 (Darrell Maier) Internal=1 Time=15989 AState=Idle 10:10:41 4052624367mS CD: CALL: 0.120801.0 Deleted 10:10:41 4052624368mS CMExtnEvt: Darrell Maier: CALL LOST (CMCauseNormal) 10:10:41 4052624368mS CMExtnEvt: Darrell Maier: Extn(3411) Calling Party Number(3411) Type(CMNTypeInternal) 10:10:41 4052624368mS CMExtnEvt: Darrell Maier: CMExtnHandler::SetCurrent( id: 120801->0 ) 10:10:41 4052624369mS CMCallEvt: ac1e14440001d7e1 0.120801.0 -1 Darrell Maier.-1: StateChange: END=X CMCSCompleted->CMCSDelete 10:10:41 4052624369mS CMARS: CMARSEndpoint::CallLost(cause=16) - Address: ac1e14440001d7e1 0.120803.0 2261 ARS for SIP Trunk - Call State: CMCSAccept 10:10:41 4052624369mS CMCallEvt: ac1e14440001d7e1 0.120803.0 -1 ARS for SIP Trunk: StateChange: END=X CMCSAccept->CMCSDelete 10:10:41 4052624370mS CMCallEvt: ac1e14440001d7e1 0.120803.0 -1 BaseEP: DELETE CMEndpoint f1687d40 TOTAL NOW=3 CALL_LIST=1 10:10:41 4052624370mS CMCallEvt: END CALL:2261 (f177e6f0) 10:10:41 4052624370mS CMTARGET: ac1e14440001d7e1 0.120801.0 -1 BaseEP: ~CMTargetHandler f18256e4 ep f17fe4b8 10:10:41 4052624371mS CMCallEvt: ac1e14440001d7e1 0.120801.0 -1 BaseEP: DELETE CMEndpoint f17fe4b8 TOTAL NOW=2 CALL_LIST=1 10:10:42 4052625991mS H323Evt: Recv: RegistrationRequest 172.30.22.102; Extn(3501), time since last RRQ-KA 55016, Endpoints registered: 3; Endpoints in registration: 0 10:10:43 4052626369mS CMExtnEvt: Darrell Maier: Recover Timer reason=CMTRWrapUp 10:10:43 4052626369mS CMExtnEvt: v=3 State, new=Idle old=PortRecoverDelay,0,0,Darrell Maier 10:10:43 4052626425mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,3411: Menu Key Pressed 4:A 10:10:46 4052629035mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,3411: Menu Key Pressed 4:A 10:10:46 4052629036mS CMCallEvt: 0000000000000000 0.120806.0 -1 BaseEP: NEW CMEndpoint f17fe4b8 TOTAL NOW=3 CALL_LIST=1 10:10:46 4052629036mS CMCallEvt: 0000000000000000 0.120806.0 -1 Darrell Maier.-1: NEW CMExtnEndpoint f17fe4b8, Name=Darrell Maier, Extn=3411, Phys Extn=3411 10:10:46 4052629036mS CMCallEvt: CREATE CALL:2263 (f177e6f0) 10:10:46 4052629036mS CMCallEvt: 0000000000000000 0.120807.0 -1 BaseEP: NEW CMEndpoint f1819a68 TOTAL NOW=4 CALL_LIST=1 10:10:46 4052629037mS CMExtnEvt: Darrell Maier: CMExtnHandler::SetCurrent( id: 0->120806 ) 10:10:46 4052629038mS CMCallEvt: ac1e14440001d7e6 0.120806.0 2263 Darrell Maier.0: StateChange: END=A CMCSIdle->CMCSDialInitiated 10:10:46 4052629039mS CMExtnEvt: v=3 State, new=Dialling old=Idle,0,0,Darrell Maier 10:10:46 4052629039mS CMTARGET: ac1e14440001d7e6 0.120806.0 2263 Darrell Maier.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=915864885440 sub= calling=3411 calling_sub= dir=out complete=1 ses=0 10:10:46 4052629039mS CMTARGET: ac1e14440001d7e6 0.120806.0 2263 Darrell Maier.0: ADD TARGET (N): number=915864885440 type=100 depth=1 nobar=1 setorig=1 ses=0 10:10:46 4052629040mS CMTARGET: ac1e14440001d7e6 0.120806.0 2263 Darrell Maier.0: SYS SC: 915864885440 2 15864885440 sc=type=Dial code=9N, num=N callinfop->sending_complete=1 secondary_dialtone= 10:10:46 4052629040mS CMARS: FindActiveARSByGroupID GroupID=52 - Found 10:10:46 4052629040mS CMARS: MakeCallTarget - Called Number: 15864885440 10:10:46 4052629040mS CMCallEvt: 0000000000000000 0.120808.0 -1 BaseEP: NEW CMEndpoint f1687d40 TOTAL NOW=5 CALL_LIST=2 10:10:46 4052629041mS CMTARGET: ac1e14440001d7e6 0.120806.0 2263 Darrell Maier.0: INITIAL TARGETING SUCCEEDED 10:10:46 4052629041mS CMTARGET: ac1e14440001d7e6 0.120806.0 2263 Darrell Maier.0: GetNoAnswerTimer:20 10:10:46 4052629041mS CMCallEvt: ac1e14440001d7e6 0.120806.0 2263 Darrell Maier.0: StateChange: END=A CMCSDialInitiated->CMCSDialled 10:10:46 4052629042mS CMExtnEvt: v=3 State, new=Proceeding old=Dialling,0,0,Darrell Maier 10:10:46 4052629042mS CMCallEvt: 0000000000000000 0.120807.0 2263 TargetingEP: StateChange: END=B CMCSIdle->CMCSOffering 10:10:46 4052629043mS CMCallEvt: 0000000000000000 0.120808.0 2263 ARS for SIP Trunk: StateChange: END=T CMCSIdle->CMCSOffering 10:10:46 4052629043mS CMCallEvt: 0000000000000000 0.120807.0 2263 TargetingEP: RequestEnd 0000000000000000 0.120808.0 2263 ARS for SIP Trunk 10:10:46 4052629044mS CMTARGET: ac1e14440001d7e6 0.120806.0 2263 Darrell Maier.0: CancelTimer CMTCNoAnswerTimeout 10:10:46 4052629044mS CMCallEvt: 0000000000000000 0.120808.0 2263 ARS for SIP Trunk: StateChange: END=B CMCSOffering->CMCSOverlapRecv 10:10:46 4052629045mS CMARS: FORM: SIP Trunk - Received Number: 15864885440 10:10:46 4052629045mS CMARS: FOUND A SHORT CODE - short_code: 1N; - Tel: 1NSi5862262080 - Called_Party: 15864885440 - Line Group Id: 17 10:10:46 4052629045mS CMARS: SetCurrentTarget: Short_Code: 1N; - Line_Group_ID: 17 10:10:46 4052629045mS CMARS: FindActiveARSByGroupID GroupID=17 - Not Found 10:10:46 4052629045mS CMLRQ: FindActiveLRQByGroupID GroupID=17 - Not Found 10:10:46 4052629045mS CMTARGET: Group Id: 17 has NOT been found in Line: 9 10:10:46 4052629045mS CMTARGET: Problem with Line Id: 17 - check_DNS 1 OperationalTest: 0, IP address: 10.1.10.150 10:10:46 4052629046mS CMARS: LINE with group ID: 17 HAS NO CHANNEL: 34 - ATTEMPT OTHER TARGETS 10:10:46 4052629046mS CMARS: ModifyCMARSTarget: Short_Code: 1N; - Line_Group_ID: 17 set line status to CMARS_OUTOFSERVICE 10:10:46 4052629046mS CMTARGET: Group Id: 17 has NOT been found in Line: 9 10:10:46 4052629047mS CMTARGET: Problem with Line Id: 17 - check_DNS 1 OperationalTest: 0, IP address: 10.1.10.150 10:10:46 4052629047mS CMARS: No Alternate ARS Or User Priority lower than ARS Priority - Remain on the Current Form: SIP Trunk 10:10:46 4052629047mS CMARS: CMARSTargetingBusy 10:10:46 4052629047mS CMCallEvt: ac1e14440001d7e6 0.120808.0 2263 ARS for SIP Trunk: StateChange: END=B CMCSOverlapRecv->CMCSAccept 10:10:46 4052629047mS CMCallEvt: ac1e14440001d7e6 0.120806.0 2263 Darrell Maier.0: StateChange: END=A CMCSDialled->CMCSRingBack 10:10:46 4052629048mS CMExtnEvt: v=3 State, new=Alerting old=Proceeding,0,0,Darrell Maier 10:10:46 4052629048mS CMCallEvt: 0000000000000000 0.120807.0 -1 TargetingEP: StateChange: END=X CMCSOffering->CMCSDelete 10:10:46 4052629048mS CMCallEvt: 0000000000000000 0.120807.0 -1 BaseEP: DELETE CMEndpoint f1819a68 TOTAL NOW=4 CALL_LIST=2 10:10:46 4052629050mS CD: CALL: 0.120806.0 BState=Ringing Cut=3 Music=0.0 Aend="Darrell Maier(3411)" (2.9) Bend="" [] (0.0) CalledNum=915864885440 () CallingNum=3411 (Darrell Maier) Internal=1 Time=14 AState=Ringing 10:10:46 4052629053mS CMMap: a=21.42 b=0.0 DTMF::AllocateRAS allocated CMRTVoicemail(f561ade4) resource busy 1, total 45 10:10:46 4052629053mS CMMap: a=21.42 b=1.65535 T 10:10:46 4052629053mS CMMap: PCG::MapBChan pcp[114]b1r0 cp_b f4f3cb88 other_cp_b f561accc type CGTypeDTMF 10:10:46 4052629053mS CMMap: a=21.42 b=2.9 M22 10:10:46 4052629053mS CMMap: DTMF::PlayTones g T[587] Tones ',EEEEE' 10:10:46 4052629053mS CMMap: Started playing tones, cp[114]b1r0 (from g null) 10:10:46 4052629053mS CMMap: cp[114]b1r0 SetOperGroup2 from g null to g null not executed, playing tones in progress ,EEEEE 10:10:46 4052629277mS RES: Mon 13/3/2017 10:10:46 FreeMem=53794416 Heap=52888788(1) Cache=905628 MemObjs=11964(18126) CMMsg=8(10) ASN=0 Buff=5200 1368 1000 7351 5 Links=56021(56365) BTree=816(2106) CPU=04.32% CPUStats=03.47%/1/5/1163/13518/14978/00.00%/1 /02.68% MCR=0 MCW=0 10:10:46 4052629278mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=55 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=69 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=0 TCP=205(TLS=91) TAPI=1 Partner=25 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034 10:10:46 4052629278mS RES4: XML MemObjs=63 PoolMem=4748404(2) FreePoolMem=4733100(0) 10:10:46 4052629278mS RES5: CLog MemObjs=519 FreePoolMem(Objs)=4212(81) TotalMem=198150 10:10:47 4052630874mS CMMap: PCG::UnmapBChan pcp[114]b1r0 cp_b f4f3cb88 other_cp_b f561accc 10:10:47 4052630874mS CMMap: a=21.42 b=2.9 M02 10:10:47 4052630874mS CMMap: a=21.42 b=0.0 T0 10:10:47 4052630875mS CMMap: a=21.42 b=0.0 DTMF::~DTMF freed CMRTUnknown(f561ade4) resource busy 0, total 45 10:10:52 4052635040mS CMARS: Retarget existing BUSY targets - Num of Busy Targets: 1 - Current Form: SIP Trunk 10:10:52 4052635041mS CMMap: a=21.42 b=0.0 DTMF::AllocateRAS allocated CMRTVoicemail(f561ade4) resource busy 1, total 45 10:10:52 4052635042mS CMMap: a=21.42 b=1.65535 T 10:10:52 4052635042mS CMMap: PCG::MapBChan pcp[114]b1r0 cp_b f4f3cb88 other_cp_b f561accc type CGTypeDTMF 10:10:52 4052635042mS CMMap: a=21.42 b=2.9 M22 10:10:52 4052635042mS CMMap: DTMF::PlayTones g T[588] Tones ',EEEEE' 10:10:52 4052635042mS CMMap: Started playing tones, cp[114]b1r0 (from g null) 10:10:52 4052635042mS CMMap: cp[114]b1r0 SetOperGroup2 from g null to g null not executed, playing tones in progress ,EEEEE 10:10:51 4052635282mS RES: Mon 13/3/2017 10:10:51 FreeMem=53794416 Heap=52888788(1) Cache=905628 MemObjs=11964(18126) CMMsg=8(10) ASN=0 Buff=5200 1371 1000 7350 5 Links=56021(56365) BTree=816(2106) CPU=04.20% CPUStats=03.38%/4/7/1163/13490/14978/00.01%/1 /02.71% MCR=0 MCW=0 10:10:51 4052635282mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=55 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=68 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=0 TCP=205(TLS=91) TAPI=1 Partner=25 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034 10:10:51 4052635282mS RES4: XML MemObjs=63 PoolMem=4748404(2) FreePoolMem=4733100(0) 10:10:51 4052635282mS RES5: CLog MemObjs=519 FreePoolMem(Objs)=4212(81) TotalMem=198150 10:10:52 4052636863mS CMMap: PCG::UnmapBChan pcp[114]b1r0 cp_b f4f3cb88 other_cp_b f561accc 10:10:52 4052636863mS CMMap: a=21.42 b=2.9 M02 10:10:52 4052636863mS CMMap: a=21.42 b=0.0 T0 10:10:52 4052636865mS CMMap: a=21.42 b=0.0 DTMF::~DTMF freed CMRTUnknown(f561ade4) resource busy 0, total 45 10:10:53 4052637238mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,3411: Menu Key Pressed 12:I 10:10:53 4052637239mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,3411: Feature Key Pressed 6:DCPLFeatureDrop 10:10:53 4052637240mS CMCallEvt: ac1e14440001d7e6 0.120806.0 2263 Darrell Maier.0: StateChange: END=A CMCSRingBack->CMCSCompleted 10:10:53 4052637240mS CMExtnEvt: v=3 State, new=PortRecoverDelay old=Alerting,0,0,Darrell Maier 10:10:53 4052637241mS PRN: CDR - TCPSend maxqueuesize=500 framecount=500 operational=0 10:10:53 4052637242mS CMLOGGING: CALL:2017/03/1310:10,00:00:00,000,3411,O,915864885440,915864885440,DarrellMaier,,,1,,"",0,n/a 10:10:53 4052637242mS CD: CALL: 0.120806.0 BState=Ringing Cut=2 Music=0.0 Aend="Darrell Maier(3411)" (2.9) Bend="" [] (0.0) CalledNum=915864885440 () CallingNum=3411 (Darrell Maier) Internal=1 Time=8206 AState=Idle 10:10:53 4052637243mS CD: CALL: 0.120806.0 Deleted 10:10:53 4052637243mS CMExtnEvt: Darrell Maier: CALL LOST (CMCauseNormal) 10:10:53 4052637243mS CMExtnEvt: Darrell Maier: Extn(3411) Calling Party Number(3411) Type(CMNTypeInternal) 10:10:53 4052637243mS CMExtnEvt: Darrell Maier: CMExtnHandler::SetCurrent( id: 120806->0 ) 10:10:53 4052637244mS CMCallEvt: ac1e14440001d7e6 0.120806.0 -1 Darrell Maier.-1: StateChange: END=X CMCSCompleted->CMCSDelete 10:10:53 4052637244mS CMARS: CMARSEndpoint::CallLost(cause=16) - Address: ac1e14440001d7e6 0.120808.0 2263 ARS for SIP Trunk - Call State: CMCSAccept 10:10:53 4052637244mS CMCallEvt: ac1e14440001d7e6 0.120808.0 -1 ARS for SIP Trunk: StateChange: END=X CMCSAccept->CMCSDelete 10:10:53 4052637245mS CMCallEvt: ac1e14440001d7e6 0.120808.0 -1 BaseEP: DELETE CMEndpoint f1687d40 TOTAL NOW=3 CALL_LIST=1 10:10:53 4052637245mS CMCallEvt: END CALL:2263 (f177e6f0) 10:10:53 4052637245mS CMTARGET: ac1e14440001d7e6 0.120806.0 -1 BaseEP: ~CMTargetHandler f18256e4 ep f17fe4b8 10:10:53 4052637246mS CMCallEvt: ac1e14440001d7e6 0.120806.0 -1 BaseEP: DELETE CMEndpoint f17fe4b8 TOTAL NOW=2 CALL_LIST=1 10:10:55 4052639244mS CMExtnEvt: Darrell Maier: Recover Timer reason=CMTRWrapUp 10:10:55 4052639244mS CMExtnEvt: v=3 State, new=Idle old=PortRecoverDelay,0,0,Darrell Maier ********** Warning: Logging to Screen Stopped **********