UNICODE-UTF8 enu 16:29:57 2662824907mS H323Evt: Recv: RegistrationRequest 192.168.1.104; Extn(252), time since last RRQ-KA 55016, Endpoints registered: 13; Endpoints in registration: 0 16:29:59 2662825564mS ISDNL3Evt: v=5 stacknum=5 State, new=Delivered, old=Proceeding id=660853 16:29:59 2662825565mS CMLineRx: v=5 CMAlerting Line: type=Q931Line 5 Call: lid=0 id=660853 in=0 IE CMIEProgressIndicator (30) cs=CMCSITUT (0), loc=CMLPrivateNetLocalUser (1), pd=CMPDInbandPattern (8) 16:29:59 2662825565mS CMCallEvt: c0a8000a000a1575 0.660853.0 180670 Q931 Trunk:5 CHAN=23: StateChange: END=B CMCSAccept->CMCSRinging 16:29:59 2662825566mS CMCallEvt: c0a8000a000a1573 0.660851.0 180670 kstacer.0: StateChange: END=A CMCSDialled->CMCSRingBack 16:29:59 2662825566mS CMExtnEvt: v=25 State, new=Alerting old=Proceeding,0,0,kstacer 16:29:59 2662825567mS CMExtnTx: v=481, p1=0 CMAlerting Line: type=DigitalExtn 9 Call: lid=0 id=660851 in=0 IE CMIEProgressIndicator (30) cs=CMCSITUT (0), loc=CMLPrivateNetLocalUser (1), pd=CMPDInbandPattern (8) IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=519899804488 IE CMIEDeviceDetail (231) c0a8000a000a1575 LOCALE=enu HW=15 VER=9 class=CMDeviceISDNTrunk type=2 number=5 channel=23 features=0x0 rx_gain=32 tx_gain=32 ep_callid=660853 ipaddr=192.168.0.10 apps=0 loc=0 em_loc=0 features2=0x0 is_spcall=1 Timed: 18/09/17 16:29 16:29:59 2662825567mS CD: CALL: 0.660851.0 BState=Ringing Cut=3 Music=0.0 Aend="kstacer(481)" (11.27) Bend="Line 5" [Line 5] (3.24) CalledNum=19899804488 () CallingNum=481 (kstacer) Internal=0 Time=14647 AState=Ringing ********** Warning: Logging to Screen Started ********** 16:30:00 2662826739mS H323Evt: Recv: RegistrationRequest 192.168.252.138; Extn(611), time since last RRQ-KA 55042, Endpoints registered: 13; Endpoints in registration: 0 16:30:03 2662830347mS H323Evt: Recv: RegistrationRequest 192.168.252.133; Extn(495), time since last RRQ-KA 55041, Endpoints registered: 13; Endpoints in registration: 0 16:30:03 2662830364mS H323Evt: Recv: RegistrationRequest 192.168.252.137; Extn(609), time since last RRQ-KA 55047, Endpoints registered: 13; Endpoints in registration: 0 16:30:03 2662830367mS ISDNL3Evt: v=5 stacknum=5 State, new=Active, old=Delivered id=660853 16:30:03 2662830368mS CMLineRx: v=5 CMConnect Line: type=Q931Line 5 Call: lid=0 id=660853 in=0 BChan: slot=0 chan=23 IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:0 R:4) number=51?19899804488 16:30:03 2662830368mS CMCallEvt: c0a8000a000a1575 0.660853.0 180670 Q931 Trunk:5 CHAN=23: StateChange: END=B CMCSRinging->CMCSConnReq 16:30:03 2662830368mS CMCallEvt: c0a8000a000a1573 0.660851.0 180670 kstacer.0: StateChange: END=A CMCSRingBack->CMCSOGConnReq 16:30:03 2662830368mS CMExtnEvt: v=25 State, new=Connected old=Alerting,0,0,kstacer 16:30:03 2662830369mS CMExtnTx: v=481, p1=0 CMConnect Line: type=DigitalExtn 9 Call: lid=0 id=660851 in=0 IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=519899804488 IE CMIEDeviceDetail (231) c0a8000a000a1575 LOCALE=enu HW=15 VER=9 class=CMDeviceISDNTrunk type=2 number=5 channel=23 features=0x0 rx_gain=32 tx_gain=32 ep_callid=660853 ipaddr=192.168.0.10 apps=0 loc=0 em_loc=0 features2=0x0 is_spcall=1 Timed: 18/09/17 16:30 16:30:03 2662830369mS CMExtnRx: v=481, p1=0 CMConnectAck Line: type=DigitalExtn 9 Call: lid=0 id=660851 in=0 16:30:03 2662830370mS CMCallEvt: c0a8000a000a1573 0.660851.0 180670 kstacer.0: StateChange: END=A CMCSOGConnReq->CMCSConnected 16:30:03 2662830370mS CMTARGET: c0a8000a000a1573 0.660851.0 180670 kstacer.0: ~CMTargetHandler f1717bbc ep f487b9e4 16:30:03 2662830371mS CMCallEvt: c0a8000a000a1575 0.660853.0 180670 Q931 Trunk:5 CHAN=23: StateChange: END=B CMCSConnReq->CMCSConnected 16:30:03 2662830372mS CMLineTx: v=5 CMConnectAck Line: type=Q931Line 5 Call: lid=0 id=660853 in=0 BChan: slot=0 chan=23 16:30:03 2662830372mS CD: CALL: 0.660851.0 BState=Connected Cut=3 Music=0.0 Aend="kstacer(481)" (11.27) Bend="Line 5" [Line 5] (3.24) CalledNum=19899804488 () CallingNum=481 (kstacer) Internal=0 Time=19452 AState=Connected 16:30:03 2662830374mS H323Evt: Recv: RegistrationRequest 192.168.252.135; Extn(605), time since last RRQ-KA 55058, Endpoints registered: 13; Endpoints in registration: 0 16:30:03 2662830585mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,361: Digit Key Pressed 5 16:30:03 2662830587mS CMCallEvt: 0000000000000000 0.660854.0 -1 BaseEP: NEW CMEndpoint f48291a8 TOTAL NOW=9 CALL_LIST=4 16:30:03 2662830587mS CMCallEvt: 0000000000000000 0.660854.0 -1 jessenmacher.-1: NEW CMExtnEndpoint f48291a8, Name=jessenmacher, Extn=361, Phys Extn=361 16:30:03 2662830587mS CMCallEvt: CREATE CALL:180671 (f176ffc0) 16:30:03 2662830587mS CMCallEvt: 0000000000000000 0.660855.0 -1 BaseEP: NEW CMEndpoint f171e7e8 TOTAL NOW=10 CALL_LIST=4 16:30:03 2662830590mS CMExtnEvt: jessenmacher: CMExtnHandler::SetCurrent( id: 0->660854 ) 16:30:03 2662830590mS CMExtnRx: v=361, p1=0 CMSetup Line: type=DigitalExtn 8 Call: lid=0 id=660854 in=0 Called[] Type=Default (100) Reason=CMDRdirect Calling[361] Type=Internal Plan=Default BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw IE CMIECallingPartyName (110)(Type=CMNameDefault) name=jessenmacher IE CMIECallingPartyKName (226)(Type=CMNameDefault) name=Jodi Essenmacher 16:30:03 2662830590mS CMCallEvt: c0a8000a000a1576 0.660854.0 180671 jessenmacher.0: StateChange: END=A CMCSIdle->CMCSDialInitiated 16:30:03 2662830590mS CMExtnEvt: v=12 State, new=Dialling old=Idle,0,0,jessenmacher 16:30:03 2662830591mS CMTARGET: c0a8000a000a1576 0.660854.0 180671 jessenmacher.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party= sub= calling=361 calling_sub= dir=out complete=0 ses=0 16:30:03 2662830592mS CMTARGET: c0a8000a000a1576 0.660854.0 180671 jessenmacher.0: ADD TARGET (N): number= type=100 depth=1 nobar=1 setorig=1 ses=0 16:30:03 2662830592mS CMCallEvt: c0a8000a000a1576 0.660854.0 180671 jessenmacher.0: StateChange: END=A CMCSDialInitiated->CMCSDialling 16:30:03 2662830593mS CMExtnTx: v=361, p1=0 CMSetupAck Line: type=DigitalExtn 8 Call: lid=0 id=660854 in=0 BChan: slot=10 chan=14 Timed: 18/09/17 16:30 16:30:03 2662830593mS CMExtnRx: v=361, p1=0 CMInformation Line: type=DigitalExtn 8 Call: lid=0 id=660854 in=0 Called[5] Type=Default (100) Reason=CMDRdirect Keypad[5] 16:30:03 2662830593mS CMTARGET: c0a8000a000a1576 0.660854.0 180671 jessenmacher.0: Setting Hard Timer 4000 16:30:03 2662830594mS CMTARGET: c0a8000a000a1576 0.660854.0 180671 jessenmacher.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=5 sub= calling=361 calling_sub= dir=out complete=0 ses=0 16:30:03 2662830594mS CMTARGET: c0a8000a000a1576 0.660854.0 180671 jessenmacher.0: ADD TARGET (N): number=5 type=100 depth=1 nobar=1 setorig=1 ses=0 16:30:03 2662830595mS CD: CALL: 0.660854.0 BState=Idle Cut=0 Music=0.0 Aend="jessenmacher(361)" (10.14) Bend="" [] (0.0) CalledNum=5 () CallingNum=361 (jessenmacher) Internal=1 Time=8 AState=Dialling 16:30:03 2662830750mS RES: Mon 18/9/2017 16:30:03 FreeMem=47610828 Heap=45507632(1) Cache=2103196 MemObjs=34130(36418) CMMsg=8(9) ASN=0 Buff=5200 1353 1000 7362 5 Links=85213(85971) BTree=3356(6936) CPU=19.06% CPUStats=18.20%/1/5/144/11946/15010/00.49%/1 /03.24% MCR=0 MCW=0 16:30:03 2662830750mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=52 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=99 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=50(TLS=5) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034 16:30:03 2662830750mS RES4: XML MemObjs=63 PoolMem=5796992(3) FreePoolMem=5781688(0) 16:30:03 2662830751mS RES5: CLog MemObjs=4866 FreePoolMem(Objs)=6968(134) TotalMem=704500 16:30:04 2662831103mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,361: Digit Key Pressed 1 16:30:04 2662831103mS CMExtnRx: v=361, p1=0 CMInformation Line: type=DigitalExtn 8 Call: lid=0 id=660854 in=0 Called[1] Type=Default (100) Reason=CMDRdirect Keypad[1] 16:30:04 2662831103mS CMTARGET: c0a8000a000a1576 0.660854.0 180671 jessenmacher.0: Setting Hard Timer 4000 16:30:04 2662831104mS CMTARGET: c0a8000a000a1576 0.660854.0 180671 jessenmacher.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=51 sub= calling=361 calling_sub= dir=out complete=0 ses=0 16:30:04 2662831104mS CMTARGET: c0a8000a000a1576 0.660854.0 180671 jessenmacher.0: ADD TARGET (N): number=51 type=100 depth=1 nobar=1 setorig=1 ses=0 16:30:04 2662831514mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,361: Digit Key Pressed 2 16:30:04 2662831514mS CMExtnRx: v=361, p1=0 CMInformation Line: type=DigitalExtn 8 Call: lid=0 id=660854 in=0 Called[2] Type=Default (100) Reason=CMDRdirect Keypad[2] 16:30:04 2662831515mS CMTARGET: c0a8000a000a1576 0.660854.0 180671 jessenmacher.0: Setting Hard Timer 4000 16:30:04 2662831515mS CMTARGET: c0a8000a000a1576 0.660854.0 180671 jessenmacher.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=512 sub= calling=361 calling_sub= dir=out complete=0 ses=0 16:30:04 2662831515mS CMTARGET: c0a8000a000a1576 0.660854.0 180671 jessenmacher.0: ADD TARGET (N): number=512 type=100 depth=1 nobar=1 setorig=1 ses=0 16:30:04 2662831856mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,361: Digit Key Pressed 4 16:30:04 2662831857mS CMExtnRx: v=361, p1=0 CMInformation Line: type=DigitalExtn 8 Call: lid=0 id=660854 in=0 Called[4] Type=Default (100) Reason=CMDRdirect Keypad[4] 16:30:04 2662831857mS CMTARGET: c0a8000a000a1576 0.660854.0 180671 jessenmacher.0: Setting Hard Timer 4000 16:30:04 2662831857mS CMTARGET: c0a8000a000a1576 0.660854.0 180671 jessenmacher.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=5124 sub= calling=361 calling_sub= dir=out complete=0 ses=0 16:30:04 2662831858mS CMTARGET: c0a8000a000a1576 0.660854.0 180671 jessenmacher.0: ADD TARGET (N): number=5124 type=100 depth=1 nobar=1 setorig=1 ses=0 16:30:05 2662832419mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,361: Digit Key Pressed 8 16:30:05 2662832420mS CMExtnRx: v=361, p1=0 CMInformation Line: type=DigitalExtn 8 Call: lid=0 id=660854 in=0 Called[8] Type=Default (100) Reason=CMDRdirect Keypad[8] 16:30:05 2662832420mS CMTARGET: c0a8000a000a1576 0.660854.0 180671 jessenmacher.0: Setting Hard Timer 4000 16:30:05 2662832420mS CMTARGET: c0a8000a000a1576 0.660854.0 180671 jessenmacher.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=51248 sub= calling=361 calling_sub= dir=out complete=0 ses=0 16:30:05 2662832420mS CMTARGET: c0a8000a000a1576 0.660854.0 180671 jessenmacher.0: ADD TARGET (N): number=51248 type=100 depth=1 nobar=1 setorig=1 ses=0 16:30:06 2662833034mS H323Evt: Recv: RegistrationRequest 192.168.1.102; Extn(250), time since last RRQ-KA 55011, Endpoints registered: 13; Endpoints in registration: 0 16:30:06 2662833408mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,361: Digit Key Pressed 6 16:30:06 2662833408mS CMExtnRx: v=361, p1=0 CMInformation Line: type=DigitalExtn 8 Call: lid=0 id=660854 in=0 Called[6] Type=Default (100) Reason=CMDRdirect Keypad[6] 16:30:06 2662833409mS CMTARGET: c0a8000a000a1576 0.660854.0 180671 jessenmacher.0: Setting Hard Timer 4000 16:30:06 2662833409mS CMTARGET: c0a8000a000a1576 0.660854.0 180671 jessenmacher.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=512486 sub= calling=361 calling_sub= dir=out complete=0 ses=0 16:30:06 2662833409mS CMTARGET: c0a8000a000a1576 0.660854.0 180671 jessenmacher.0: ADD TARGET (N): number=512486 type=100 depth=1 nobar=1 setorig=1 ses=0 16:30:06 2662833877mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,361: Digit Key Pressed 2 16:30:06 2662833877mS CMExtnRx: v=361, p1=0 CMInformation Line: type=DigitalExtn 8 Call: lid=0 id=660854 in=0 Called[2] Type=Default (100) Reason=CMDRdirect Keypad[2] 16:30:06 2662833878mS CMTARGET: c0a8000a000a1576 0.660854.0 180671 jessenmacher.0: Setting Hard Timer 4000 16:30:06 2662833878mS CMTARGET: c0a8000a000a1576 0.660854.0 180671 jessenmacher.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=5124862 sub= calling=361 calling_sub= dir=out complete=0 ses=0 16:30:06 2662833878mS CMTARGET: c0a8000a000a1576 0.660854.0 180671 jessenmacher.0: ADD TARGET (N): number=5124862 type=100 depth=1 nobar=1 setorig=1 ses=0 16:30:07 2662834500mS SIP Tx: UDP 10.1.0.21:5060 -> 192.168.1.108:5060 OPTIONS sip:192.168.1.108 SIP/2.0 Via: SIP/2.0/UDP 10.1.0.21:5060;rport;branch=z9hG4bKd7671e2e5bae37ec6730c695e8c19502 From: ;tag=058ee0ff92e02683 To: Call-ID: e11219c9b68ad9885051cc4830e6dae2 CSeq: 1103467298 OPTIONS Contact: Max-Forwards: 70 Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,INFO,REFER,NOTIFY,UPDATE Supported: timer User-Agent: IP Office 9.1.6.0 build 153 Content-Length: 0 16:30:07 2662834533mS SIP Rx: UDP 192.168.1.108:5060 -> 10.1.0.21:5060 SIP/2.0 200 OK Via: SIP/2.0/UDP 10.1.0.21:5060;branch=z9hG4bKd7671e2e5bae37ec6730c695e8c19502;received=10.1.0.21;rport=5060 From: ;tag=058ee0ff92e02683 To: ;tag=1c1648526434 Call-ID: e11219c9b68ad9885051cc4830e6dae2 CSeq: 1103467298 OPTIONS Contact: ;expires=0 Supported: 100rel Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE Server: MP-124E FXS/v.6.60A.332.002 X-Resources: telchs=10/1;mediachs=0/0 Accept: application/sdp, application/simple-message-summary, message/sipfrag Content-Type: application/sdp Content-Length: 262 v=0 o=AudiocodesGW 1648548352 1648548347 IN IP4 192.168.1.108 s=Phone-Call c=IN IP4 192.168.1.108 t=0 0 m=audio 6000 RTP/AVP 8 0 101 a=ptime:20 a=sendrecv a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15,16 16:30:07 2662834538mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,361: Digit Key Pressed 8 16:30:07 2662834538mS CMExtnRx: v=361, p1=0 CMInformation Line: type=DigitalExtn 8 Call: lid=0 id=660854 in=0 Called[8] Type=Default (100) Reason=CMDRdirect Keypad[8] 16:30:07 2662834539mS CMTARGET: c0a8000a000a1576 0.660854.0 180671 jessenmacher.0: Setting Hard Timer 4000 16:30:07 2662834539mS CMTARGET: c0a8000a000a1576 0.660854.0 180671 jessenmacher.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=51248628 sub= calling=361 calling_sub= dir=out complete=0 ses=0 16:30:07 2662834539mS CMTARGET: c0a8000a000a1576 0.660854.0 180671 jessenmacher.0: ADD TARGET (N): number=51248628 type=100 depth=1 nobar=1 setorig=1 ses=0 16:30:08 2662835585mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,361: Digit Key Pressed 2 16:30:08 2662835586mS CMExtnRx: v=361, p1=0 CMInformation Line: type=DigitalExtn 8 Call: lid=0 id=660854 in=0 Called[2] Type=Default (100) Reason=CMDRdirect Keypad[2] 16:30:08 2662835586mS CMTARGET: c0a8000a000a1576 0.660854.0 180671 jessenmacher.0: Setting Hard Timer 4000 16:30:08 2662835586mS CMTARGET: c0a8000a000a1576 0.660854.0 180671 jessenmacher.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=512486282 sub= calling=361 calling_sub= dir=out complete=0 ses=0 16:30:08 2662835587mS CMTARGET: c0a8000a000a1576 0.660854.0 180671 jessenmacher.0: ADD TARGET (N): number=512486282 type=100 depth=1 nobar=1 setorig=1 ses=0 16:30:09 2662835898mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,361: Digit Key Pressed 5 16:30:09 2662835899mS CMExtnRx: v=361, p1=0 CMInformation Line: type=DigitalExtn 8 Call: lid=0 id=660854 in=0 Called[5] Type=Default (100) Reason=CMDRdirect Keypad[5] 16:30:09 2662835899mS CMTARGET: c0a8000a000a1576 0.660854.0 180671 jessenmacher.0: Setting Hard Timer 4000 16:30:09 2662835899mS CMTARGET: c0a8000a000a1576 0.660854.0 180671 jessenmacher.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=5124862825 sub= calling=361 calling_sub= dir=out complete=0 ses=0 16:30:09 2662835899mS CMTARGET: c0a8000a000a1576 0.660854.0 180671 jessenmacher.0: ADD TARGET (N): number=5124862825 type=100 depth=1 nobar=1 setorig=1 ses=0 16:30:10 2662836211mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,361: Digit Key Pressed 6 16:30:10 2662836212mS CMExtnRx: v=361, p1=0 CMInformation Line: type=DigitalExtn 8 Call: lid=0 id=660854 in=0 Called[6] Type=Default (100) Reason=CMDRdirect Keypad[6] 16:30:10 2662836212mS CMTARGET: c0a8000a000a1576 0.660854.0 180671 jessenmacher.0: Setting Hard Timer 4000 16:30:10 2662836212mS CMTARGET: c0a8000a000a1576 0.660854.0 180671 jessenmacher.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=51248628256 sub= calling=361 calling_sub= dir=out complete=0 ses=0 16:30:10 2662836212mS CMTARGET: c0a8000a000a1576 0.660854.0 180671 jessenmacher.0: ADD TARGET (N): number=51248628256 type=100 depth=1 nobar=1 setorig=1 ses=0 16:30:10 2662836475mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,361: Digit Key Pressed 1 16:30:10 2662836476mS CMExtnRx: v=361, p1=0 CMInformation Line: type=DigitalExtn 8 Call: lid=0 id=660854 in=0 Called[1] Type=Default (100) Reason=CMDRdirect Keypad[1] 16:30:10 2662836476mS CMTARGET: c0a8000a000a1576 0.660854.0 180671 jessenmacher.0: Setting Hard Timer 4000 16:30:10 2662836476mS CMTARGET: c0a8000a000a1576 0.660854.0 180671 jessenmacher.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=512486282561 sub= calling=361 calling_sub= dir=out complete=0 ses=0 16:30:10 2662836477mS CMTARGET: c0a8000a000a1576 0.660854.0 180671 jessenmacher.0: ADD TARGET (N): number=512486282561 type=100 depth=1 nobar=1 setorig=1 ses=0 16:30:10 2662836653mS RES: Mon 18/9/2017 16:30:10 FreeMem=47567092 Heap=45474844(1) Cache=2092248 MemObjs=34228(36418) CMMsg=8(9) ASN=0 Buff=5200 1353 1000 7362 5 Links=85217(85971) BTree=3356(6936) CPU=19.26% CPUStats=19.08%/2/8/144/11911/15010/00.48%/1 /03.24% MCR=0 MCW=0 16:30:10 2662836654mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=52 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=99 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=50(TLS=5) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034 16:30:10 2662836654mS RES4: XML MemObjs=63 PoolMem=5796992(3) FreePoolMem=5781688(0) 16:30:10 2662836654mS RES5: CLog MemObjs=4866 FreePoolMem(Objs)=6968(134) TotalMem=704500 16:30:14 2662840476mS CMTARGET: c0a8000a000a1576 0.660854.0 180671 jessenmacher.0: TimerExpired cause=CMTCDelayedProcessing 16:30:14 2662840476mS CMTARGET: c0a8000a000a1576 0.660854.0 180671 jessenmacher.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=512486282561 sub= calling=361 calling_sub= dir=out complete=1 ses=0 16:30:14 2662840476mS CMTARGET: c0a8000a000a1576 0.660854.0 180671 jessenmacher.0: ADD TARGET (N): number=512486282561 type=100 depth=1 nobar=1 setorig=1 ses=0 16:30:14 2662840477mS CMTARGET: c0a8000a000a1576 0.660854.0 180671 jessenmacher.0: USER SC: 512486282561 3 12486282561 sc=type=Dial code=5N;, num=NSi9892698242 16:30:14 2662840477mS CMARS: FindActiveARSByGroupID GroupID=0 - Not Found 16:30:14 2662840477mS CMLRQ: FindActiveLRQByGroupID GroupID=0 - Not Found 16:30:14 2662840478mS CMCallEvt: 0000000000000000 0.660856.0 -1 BaseEP: NEW CMEndpoint f17705c8 TOTAL NOW=11 CALL_LIST=5 16:30:14 2662840478mS CMTARGET: ISDN BChannel 23: in-service check = 1 16:30:14 2662840478mS CMTARGET: ISDN BChannel 23: in-service check = 1 16:30:14 2662840480mS CMTARGET: DIAL LINE: 180671 GROUP = 0 SUCCESS = f17705c8 16:30:14 2662840480mS CMTARGET: c0a8000a000a1576 0.660854.0 180671 jessenmacher.0: INITIAL TARGETING SUCCEEDED 16:30:14 2662840480mS CMTARGET: c0a8000a000a1576 0.660854.0 180671 jessenmacher.0: GetNoAnswerTimer:15 16:30:14 2662840481mS CMCallEvt: c0a8000a000a1576 0.660854.0 180671 jessenmacher.0: StateChange: END=A CMCSDialling->CMCSDialled 16:30:14 2662840481mS CMExtnEvt: v=12 State, new=Proceeding old=Dialling,0,0,jessenmacher 16:30:14 2662840481mS CMExtnTx: v=361, p1=0 CMProceeding Line: type=DigitalExtn 8 Call: lid=0 id=660854 in=0 Timed: 18/09/17 16:30 16:30:14 2662840481mS CMCallEvt: 0000000000000000 0.660855.0 180671 TargetingEP: StateChange: END=B CMCSIdle->CMCSOffering 16:30:14 2662840482mS CMCallEvt: c0a8000a000a1578 0.660856.0 180671 Q931 Trunk:6 CHAN=23: StateChange: END=T CMCSIdle->CMCSOffering 16:30:14 2662840483mS PRN: Setting configured voice gain for ch 23. 16:30:14 2662840483mS CMLineTx: v=6 CMSetup Line: type=Q931Line 6 Call: lid=0 id=660856 in=0 Called[12486282561] Type=National (2) Reason=CMDRdirect Calling[9892698242] Type=National Plan=ISDN BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw BChan: slot=0 chan=23 Timed: 18/09/17 16:30 Locale: enu 16:30:14 2662840483mS CD: CALL: 0.660854.0 BState=Idle Cut=1 Music=0.0 Aend="jessenmacher(361)" (10.14) Bend="Line 6" [Line 6] (0.0) CalledNum=512486282561 () CallingNum=361 (jessenmacher) Internal=0 Time=9896 AState=Dialled 16:30:14 2662840485mS ISDNL3Evt: v=6 stacknum=6 State, new=Initiated, old=NullState id=660856 16:30:14 2662840508mS ISDNL3Evt: v=6 stacknum=6 State, new=Proceeding, old=Initiated id=660856 16:30:14 2662840508mS CMLineRx: v=6 CMProceeding Line: type=Q931Line 6 Call: lid=0 id=660856 in=0 BChan: slot=0 chan=23 16:30:14 2662840509mS CMCallEvt: 0000000000000000 0.660855.0 180671 TargetingEP: RequestEnd c0a8000a000a1578 0.660856.0 180671 Q931 Trunk:6 CHAN=23 16:30:14 2662840509mS CMTARGET: c0a8000a000a1576 0.660854.0 180671 jessenmacher.0: CancelTimer CMTCNoAnswerTimeout 16:30:14 2662840509mS CMCallEvt: 0000000000000000 0.660855.0 -1 BaseEP: DELETE CMEndpoint f171e7e8 TOTAL NOW=10 CALL_LIST=5 16:30:14 2662840510mS CMCallEvt: c0a8000a000a1578 0.660856.0 180671 Q931 Trunk:6 CHAN=23: StateChange: END=B CMCSOffering->CMCSAccept 16:30:14 2662840511mS CD: CALL: 0.660854.0 BState=Ringing Cut=3 Music=0.0 Aend="jessenmacher(361)" (10.14) Bend="Line 6" [Line 6] (3.56) CalledNum=12486282561 () CallingNum=361 (jessenmacher) Internal=0 Time=9923 AState=Dialled 16:30:14 2662840512mS CMMap: PCG::MapBChan pcp[191]b1r0 cp_b f4a5f998 other_cp_b 0 type CGTypeSimple 16:30:14 2662840512mS CMMap: PCG::MapBChan pcp[117]b1r0 cp_b f5211db4 other_cp_b f4a5f998 type CGTypeSimple 16:30:14 2662840512mS CMMap: a=10.14 b=3.56 M12 16:30:24 2662850081mS CMTARGET: ISDN BChannel 1: in-service check = 1 16:30:24 2662850081mS ISDNL3Evt: v=6 stacknum=6 State, new=Present, old=NullState id=15 16:30:24 2662850082mS CMLineRx: v=6 CMSetup Line: type=Q931Line 6 Call: lid=6 id=15 in=1 Called[912486282561] Type=Unknown (0) Reason=CMDRdirect SndComp Calling[519892698242] Type=Unknown Plan=ISDN Pres=Allowed (0) BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw BChan: slot=0 chan=1 16:30:24 2662850082mS PRN: Q931Trunk: Found QBChannel to match 0.1 --> 3.34 16:30:24 2662850082mS CMCallEvt: 0000000000000000 0.660857.0 -1 BaseEP: NEW CMEndpoint f16b5f90 TOTAL NOW=11 CALL_LIST=5 16:30:24 2662850083mS CMTARGET: ISDN BChannel 1: in-service check = 1 16:30:24 2662850083mS CMTARGET: ISDN BChannel 1: in-service check = 1 16:30:24 2662850083mS CMCallEvt: CREATE CALL:180672 (f162ca00) 16:30:24 2662850083mS CMCallEvt: 0000000000000000 0.660858.0 -1 BaseEP: NEW CMEndpoint f171e7e8 TOTAL NOW=12 CALL_LIST=5 16:30:24 2662850086mS CD: CALL: 6.15.1 BState=Idle Cut=1 Music=0.0 Aend="Line 6" (3.34) Bend="" [] (0.0) CalledNum=912486282561 () CallingNum=519892698242 () Internal=0 Time=3 AState=Idle 16:30:24 2662850086mS CMCallEvt: c0a8000a0000000f 6.15.1 180672 Q931 Trunk:6 CHAN=1: StateChange: END=A CMCSIdle->CMCSDialInitiated 16:30:24 2662850087mS CMTARGET: c0a8000a0000000f 6.15.1 180672 Q931 Trunk:6 CHAN=1: LOOKUP CALL ROUTE: GID=0 type=0 called_party=912486282561 sub= calling=519892698242 calling_sub= dir=in complete=1 ses=0 16:30:24 2662850089mS CMLOGGING: CALL:2017/09/1816:30,00:00:00,000,519892698242,I,912486282561,912486282561,,,,0,,"",0,n/a 16:30:24 2662850089mS CD: CALL: 6.15.1 BState=Idle Cut=0 Music=0.0 Aend="Line 6" (3.34) Bend="" [] (0.0) CalledNum=912486282561 () CallingNum=519892698242 () Internal=0 Time=6 AState=Dialling 16:30:24 2662850089mS CD: CALL: 6.15.1 Deleted 16:30:24 2662850090mS CMLineTx: v=6 CMReleaseComp Line: type=Q931Line 6 Call: lid=6 id=15 in=1 Cause=88, Incompatible destination 16:30:24 2662850090mS CMCallEvt: c0a8000a0000000f 6.15.1 -1 Q931 Trunk:6 CHAN=1: StateChange: END=X CMCSDialInitiated->CMCSDelete 16:30:24 2662850090mS CMCallEvt: 0000000000000000 0.660858.0 -1 BaseEP: DELETE CMEndpoint f171e7e8 TOTAL NOW=11 CALL_LIST=5 16:30:24 2662850090mS CMCallEvt: END CALL:180672 (f162ca00) 16:30:24 2662850091mS CMTARGET: ISDN BChannel 1: in-service check = 1 16:30:24 2662850091mS CMTARGET: ISDN BChannel 1: in-service check = 1 16:30:24 2662850092mS CMTARGET: c0a8000a0000000f 6.15.1 -1 BaseEP: ~CMTargetHandler f1749e0c ep f16b5f90 16:30:24 2662850092mS CMCallEvt: c0a8000a0000000f 6.15.1 -1 BaseEP: DELETE CMEndpoint f16b5f90 TOTAL NOW=10 CALL_LIST=5 16:30:24 2662850094mS ISDNL3Evt: v=6 stacknum=6 State, new=NullState, old=Present id=15 16:30:24 2662850107mS ISDNL3Evt: v=6 stacknum=6 State, new=ReleaseReq, old=Proceeding id=660856 16:30:24 2662850114mS ISDNL3Evt: v=6 stacknum=6 State, new=NullState, old=ReleaseReq id=660856 16:30:24 2662850115mS CMLineRx: v=6 CMReleaseComp Line: type=Q931Line 6 Call: lid=0 id=660856 in=0 BChan: slot=0 chan=23 Cause=88, Incompatible destination 16:30:24 2662850115mS CMCallEvt: c0a8000a000a1578 0.660856.0 180671 Q931 Trunk:6 CHAN=23: StateChange: END=B CMCSAccept->CMCSCompleted 16:30:24 2662850117mS CMLOGGING: CALL:2017/09/1816:30,00:00:00,000,361,O,12486282561,512486282561,jessenmacher,,,0,,"",0,n/a 16:30:24 2662850117mS CD: CALL: 0.660854.0 BState=Disconnecting Cut=1 Music=0.0 Aend="jessenmacher(361)" (10.14) Bend="Line 6" [Line 6] (3.56) CalledNum=12486282561 () CallingNum=361 (jessenmacher) Internal=0 Time=19530 AState=Dialled 16:30:24 2662850117mS CD: CALL: 0.660854.0 Deleted 16:30:24 2662850118mS CMExtnEvt: jessenmacher: CALL LOST (CMCauseIncompatible) 16:30:24 2662850118mS CMExtnEvt: jessenmacher: Extn(361) Calling Party Number(361) Type(CMNTypeInternal) 16:30:24 2662850119mS CMCallEvt: c0a8000a000a1576 0.660854.0 -1 jessenmacher.0: StateChange: END=X CMCSDialled->CMCSCompletedTone 16:30:24 2662850119mS CMExtnEvt: v=12 State, new=CMESCompleted old=Proceeding,0,0,jessenmacher 16:30:24 2662850120mS CMCallEvt: c0a8000a000a1578 0.660856.0 -1 Q931 Trunk:6 CHAN=23: StateChange: END=X CMCSCompleted->CMCSDelete 16:30:24 2662850120mS CMCallEvt: END CALL:180671 (f176ffc0) 16:30:24 2662850121mS CMTARGET: ISDN BChannel 23: in-service check = 1 16:30:24 2662850121mS CMTARGET: ISDN BChannel 23: in-service check = 1 16:30:24 2662850121mS CMCallEvt: c0a8000a000a1578 0.660856.0 -1 BaseEP: DELETE CMEndpoint f17705c8 TOTAL NOW=9 CALL_LIST=4 16:30:24 2662850123mS CMMap: PCG::UnmapBChan pcp[191]b1r0 cp_b f4a5f998 other_cp_b f5211db4 16:30:24 2662850123mS CMMap: a=3.56 b=10.14 M02 16:30:24 2662850123mS CMMap: PCG::UnmapBChan pcp[117]b1r0 cp_b f5211db4 other_cp_b 0 16:30:24 2662850124mS CMMap: a=21.43 b=0.0 DTMF::AllocateRAS allocated CMRTVoicemail(f5396f70) resource busy 3, total 45 16:30:24 2662850124mS CMMap: a=21.43 b=1.65535 T 16:30:24 2662850124mS CMMap: a=21.43 b=10.14 M22 16:30:24 2662850166mS RES: Mon 18/9/2017 16:30:23 FreeMem=47623140 Heap=45507632(1) Cache=2115508 MemObjs=34111(36418) CMMsg=8(9) ASN=0 Buff=5200 1337 1000 7362 5 Links=85230(85971) BTree=3357(6936) CPU=18.53% CPUStats=20.35%/11/17/144/11702/15010/00.74% /1/03.29% MCR=0 MCW=0 16:30:24 2662850166mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=52 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=107 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=50(TLS=5) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034 16:30:24 2662850166mS RES4: XML MemObjs=63 PoolMem=5796992(3) FreePoolMem=5781688(0) 16:30:24 2662850166mS RES5: CLog MemObjs=4866 FreePoolMem(Objs)=6968(134) TotalMem=704500 16:30:25 2662852193mS CMExtnRx: v=481, p1=0 CMReleaseComp Line: type=DigitalExtn 9 Call: lid=0 id=660851 in=0 16:30:25 2662852193mS CMCallEvt: c0a8000a000a1573 0.660851.0 180670 kstacer.0: StateChange: END=A CMCSConnected->CMCSCompleted 16:30:25 2662852194mS CMExtnEvt: v=25 State, new=PortRecoverDelay old=Connected,0,0,kstacer 16:30:25 2662852195mS CMLOGGING: CALL:2017/09/1816:29,00:00:21,004,481,O,19899804488,519899804488,kstacer,,,0,,"",0,n/a 16:30:25 2662852196mS CD: CALL: 0.660851.0 BState=Connected Cut=2 Music=0.0 Aend="kstacer(481)" (11.27) Bend="Line 5" [Line 5] (3.24) CalledNum=19899804488 () CallingNum=481 (kstacer) Internal=0 Time=41276 AState=Idle 16:30:25 2662852196mS CD: CALL: 0.660851.0 Deleted 16:30:25 2662852196mS CMExtnEvt: kstacer: CALL LOST (CMCauseNormal) 16:30:25 2662852196mS CMExtnEvt: kstacer: Extn(481) Calling Party Number(481) Type(CMNTypeInternal) 16:30:25 2662852197mS CMExtnEvt: kstacer: CMExtnHandler::SetCurrent( id: 660851->0 ) 16:30:25 2662852197mS CMCallEvt: c0a8000a000a1573 0.660851.0 -1 kstacer.-1: StateChange: END=X CMCSCompleted->CMCSDelete 16:30:25 2662852198mS CMLineTx: v=5 CMDisconnect Line: type=Q931Line 5 Call: lid=0 id=660853 in=0 Cause=16, Normal call clearing 16:30:25 2662852199mS CMCallEvt: c0a8000a000a1575 0.660853.0 -1 Q931 Trunk:5 CHAN=23: StateChange: END=X CMCSConnected->CMCSCompleted 16:30:25 2662852199mS CMCallEvt: END CALL:180670 (f1740e5c) 16:30:25 2662852200mS CMCallEvt: c0a8000a000a1573 0.660851.0 -1 BaseEP: DELETE CMEndpoint f487b9e4 TOTAL NOW=8 CALL_LIST=3 16:30:25 2662852202mS ISDNL3Evt: v=5 stacknum=5 State, new=DiscReq, old=Active id=660853 16:30:25 2662852203mS CMMap: PCG::UnmapBChan pcp[94]b1r0 cp_b f534dbc8 other_cp_b f4965280 16:30:25 2662852203mS CMMap: a=11.27 b=3.24 M02 16:30:25 2662852203mS CMMap: PCG::UnmapBChan pcp[245]b1r0 cp_b f4965280 other_cp_b 0 16:30:25 2662852210mS ISDNL3Evt: v=5 stacknum=5 State, new=NullState, old=DiscReq id=660853 16:30:25 2662852211mS CMLineRx: v=5 CMReleaseComp Line: type=Q931Line 5 Call: lid=0 id=660853 in=0 BChan: slot=0 chan=23 16:30:25 2662852211mS CMCallEvt: c0a8000a000a1575 0.660853.0 -1 Q931 Trunk:5 CHAN=23: StateChange: END=X CMCSCompleted->CMCSDelete 16:30:25 2662852211mS CMTARGET: ISDN BChannel 23: in-service check = 1 16:30:25 2662852212mS CMTARGET: ISDN BChannel 23: in-service check = 1 16:30:25 2662852212mS CMCallEvt: c0a8000a000a1575 0.660853.0 -1 BaseEP: DELETE CMEndpoint f47a2d98 TOTAL NOW=7 CALL_LIST=3 16:30:27 2662854197mS CMExtnEvt: kstacer: Recover Timer reason=CMTRWrapUp 16:30:27 2662854197mS CMExtnEvt: v=25 State, new=Idle old=PortRecoverDelay,0,0,kstacer 16:30:27 2662854198mS CMExtnTx: v=481, p1=0 CMVoiceMailStatus Line: type=DigitalExtn 9 Call: lid=0 id=-1 in=0 Called[kstacer Msgs=0 Old=0 Sav=0] Type=Default (100) Reason=CMDRdirect Calling[00000000] Type=Default Plan=Default Display [kstacer Msgs=0] Timed: 18/09/17 16:30 16:30:27 2662854363mS CMExtnEvt: jwood: No user activity 16:30:28 2662855495mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,361: Menu Key Pressed 12:I 16:30:28 2662855497mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,361: Feature Key Pressed 6:DCPLFeatureDrop 16:30:28 2662855497mS CMExtnEvt: jessenmacher: CMExtnHandler::SetCurrent( id: 660854->0 ) 16:30:28 2662855497mS CMExtnTx: v=361, p1=0 CMReleaseComp Line: type=DigitalExtn 8 Call: lid=0 id=660854 in=0 Called[512486282561] Type=Default (100) Reason=CMDRdirect Calling[361] Type=Internal Plan=Default Cause=2, No route to specific transit network/(5ESS)Calling party off hold Timed: 18/09/17 16:30 16:30:28 2662855498mS CMCallEvt: c0a8000a000a1576 0.660854.0 -1 jessenmacher.-1: StateChange: END=X CMCSCompletedTone->CMCSDelete 16:30:28 2662855498mS CMExtnEvt: v=12 State, new=PortRecoverDelay old=CMESCompleted,0,0,jessenmacher 16:30:28 2662855498mS CMTARGET: c0a8000a000a1576 0.660854.0 -1 BaseEP: ~CMTargetHandler f1717bbc ep f48291a8 16:30:28 2662855499mS CMCallEvt: c0a8000a000a1576 0.660854.0 -1 BaseEP: DELETE CMEndpoint f48291a8 TOTAL NOW=6 CALL_LIST=3 16:30:28 2662855501mS CMMap: a=21.43 b=10.14 M02 16:30:28 2662855502mS CMMap: a=21.43 b=0.0 T0 16:30:28 2662855503mS CMMap: a=21.43 b=0.0 DTMF::~DTMF freed CMRTUnknown(f5396f70) resource busy 2, total 45 16:30:29 2662855683mS RES: Mon 18/9/2017 16:30:29 FreeMem=47661780 Heap=45507632(1) Cache=2154148 MemObjs=34060(36418) CMMsg=8(9) ASN=0 Buff=5200 1353 1000 7361 5 Links=85196(85971) BTree=3355(6936) CPU=19.60% CPUStats=36.12%/11/18/144/9366/15010/00.94%/ 1/03.47% MCR=0 MCW=0 16:30:29 2662855684mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=52 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=96 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=50(TLS=5) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034 16:30:29 2662855684mS RES4: XML MemObjs=63 PoolMem=5796992(3) FreePoolMem=5781688(0) 16:30:29 2662855684mS RES5: CLog MemObjs=4866 FreePoolMem(Objs)=6968(134) TotalMem=704500 16:30:31 2662857498mS CMExtnEvt: jessenmacher: Recover Timer reason=CMTRWrapUp 16:30:31 2662857498mS CMExtnEvt: v=12 State, new=Idle old=PortRecoverDelay,0,0,jessenmacher 16:30:31 2662857499mS CMExtnTx: v=361, p1=0 CMVoiceMailStatus Line: type=DigitalExtn 8 Call: lid=0 id=-1 in=0 Called[jessenmacher Msgs=0 Old=0 Sav=15] Type=Default (100) Reason=CMDRdirect Calling[00000000] Type=Default Plan=Default Display [jessenmacher Msgs=0] Timed: 18/09/17 16:30 16:30:34 2662860979mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,361: Digit Key Pressed 5 16:30:34 2662860981mS CMCallEvt: 0000000000000000 0.660859.0 -1 BaseEP: NEW CMEndpoint f48291a8 TOTAL NOW=7 CALL_LIST=3 16:30:34 2662860981mS CMCallEvt: 0000000000000000 0.660859.0 -1 jessenmacher.-1: NEW CMExtnEndpoint f48291a8, Name=jessenmacher, Extn=361, Phys Extn=361 16:30:34 2662860981mS CMCallEvt: CREATE CALL:180673 (f1740e5c) 16:30:34 2662860982mS CMCallEvt: 0000000000000000 0.660860.0 -1 BaseEP: NEW CMEndpoint f171e7e8 TOTAL NOW=8 CALL_LIST=3 16:30:34 2662860984mS CMExtnEvt: jessenmacher: CMExtnHandler::SetCurrent( id: 0->660859 ) 16:30:34 2662860984mS CMExtnRx: v=361, p1=0 CMSetup Line: type=DigitalExtn 8 Call: lid=0 id=660859 in=0 Called[] Type=Default (100) Reason=CMDRdirect Calling[361] Type=Internal Plan=Default BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw IE CMIECallingPartyName (110)(Type=CMNameDefault) name=jessenmacher IE CMIECallingPartyKName (226)(Type=CMNameDefault) name=Jodi Essenmacher 16:30:34 2662860984mS CMCallEvt: c0a8000a000a157b 0.660859.0 180673 jessenmacher.0: StateChange: END=A CMCSIdle->CMCSDialInitiated 16:30:34 2662860985mS CMExtnEvt: v=12 State, new=Dialling old=Idle,0,0,jessenmacher 16:30:34 2662860985mS CMTARGET: c0a8000a000a157b 0.660859.0 180673 jessenmacher.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party= sub= calling=361 calling_sub= dir=out complete=0 ses=0 16:30:34 2662860986mS CMTARGET: c0a8000a000a157b 0.660859.0 180673 jessenmacher.0: ADD TARGET (N): number= type=100 depth=1 nobar=1 setorig=1 ses=0 16:30:34 2662860986mS CMCallEvt: c0a8000a000a157b 0.660859.0 180673 jessenmacher.0: StateChange: END=A CMCSDialInitiated->CMCSDialling 16:30:34 2662860987mS CMExtnTx: v=361, p1=0 CMSetupAck Line: type=DigitalExtn 8 Call: lid=0 id=660859 in=0 BChan: slot=10 chan=14 Timed: 18/09/17 16:30 16:30:34 2662860987mS CMExtnRx: v=361, p1=0 CMInformation Line: type=DigitalExtn 8 Call: lid=0 id=660859 in=0 Called[5] Type=Default (100) Reason=CMDRdirect Keypad[5] 16:30:34 2662860987mS CMTARGET: c0a8000a000a157b 0.660859.0 180673 jessenmacher.0: Setting Hard Timer 4000 16:30:34 2662860988mS CMTARGET: c0a8000a000a157b 0.660859.0 180673 jessenmacher.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=5 sub= calling=361 calling_sub= dir=out complete=0 ses=0 16:30:34 2662860988mS CMTARGET: c0a8000a000a157b 0.660859.0 180673 jessenmacher.0: ADD TARGET (N): number=5 type=100 depth=1 nobar=1 setorig=1 ses=0 16:30:34 2662860989mS CD: CALL: 0.660859.0 BState=Idle Cut=0 Music=0.0 Aend="jessenmacher(361)" (10.14) Bend="" [] (0.0) CalledNum=5 () CallingNum=361 (jessenmacher) Internal=1 Time=8 AState=Dialling 16:30:35 2662861192mS RES: Mon 18/9/2017 16:30:34 FreeMem=47634964 Heap=45507632(1) Cache=2127332 MemObjs=34083(36418) CMMsg=8(9) ASN=0 Buff=5200 1353 1000 7363 5 Links=85199(85971) BTree=3358(6936) CPU=19.01% CPUStats=18.30%/11/18/144/12054/15010/00.53% /0/03.25% MCR=0 MCW=0 16:30:35 2662861193mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=52 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=97 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=50(TLS=5) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034 16:30:35 2662861193mS RES4: XML MemObjs=63 PoolMem=5796992(3) FreePoolMem=5781688(0) 16:30:35 2662861193mS RES5: CLog MemObjs=4866 FreePoolMem(Objs)=6968(134) TotalMem=704500 16:30:35 2662861372mS CMExtnRx: v=471, p1=0 CMReleaseComp Line: type=DigitalExtn 9 Call: lid=0 id=660787 in=0 16:30:35 2662861372mS CMCallEvt: c0a8000a000a1533 0.660787.0 180642 dkidd.0: StateChange: END=B CMCSConnected->CMCSCompleted 16:30:35 2662861373mS CMExtnEvt: v=20 State, new=PortRecoverDelay old=Connected,0,0,dkidd 16:30:35 2662861374mS CMLOGGING: CALL:2017/09/1816:18,00:12:04,012,517044899768,I,729,9892699942,KREGER,MICHELL,,,0,,"",0,n/a 16:30:35 2662861374mS CD: CALL: 6.5.1 BState=Disconnecting Cut=1 Music=0.0 Aend="Line 6" (3.36) Bend="dkidd(471)" [dkidd(471)] (11.22) CalledNum=729 (County Clerk) CallingNum=517044899768 (KREGER, MICHELL) Internal=0 Time=730103 AState=Connected 16:30:35 2662861375mS CD: CALL: 6.5.1 Deleted 16:30:35 2662861376mS CMLineTx: v=6 CMDisconnect Line: type=Q931Line 6 Call: lid=6 id=5 in=1 Cause=16, Normal call clearing 16:30:35 2662861376mS CMCallEvt: c0a8000a00000005 6.5.1 -1 Q931 Trunk:6 CHAN=3: StateChange: END=X CMCSConnected->CMCSCompleted 16:30:35 2662861376mS CMExtnEvt: dkidd: CALL LOST (CMCauseNormal) 16:30:35 2662861377mS CMExtnEvt: dkidd: Extn(471) Calling Party Number(517044899768) Type(CMNTypeUnknown) 16:30:35 2662861377mS CMExtnEvt: dkidd: CMExtnHandler::SetCurrent( id: 660787->0 ) 16:30:35 2662861377mS CMCallEvt: c0a8000a000a1533 0.660787.0 -1 dkidd.-1: StateChange: END=X CMCSCompleted->CMCSDelete 16:30:35 2662861377mS CMCallEvt: END CALL:180642 (f4cf64d8) 16:30:35 2662861378mS CMCallEvt: c0a8000a000a1533 0.660787.0 -1 BaseEP: DELETE CMEndpoint f4832b2c TOTAL NOW=7 CALL_LIST=3 16:30:35 2662861381mS CMMap: PCG::UnmapBChan pcp[97]b1r0 cp_b f5215b94 other_cp_b f49a5038 16:30:35 2662861381mS CMMap: a=11.22 b=3.36 M02 16:30:35 2662861381mS CMMap: PCG::UnmapBChan pcp[227]b1r0 cp_b f49a5038 other_cp_b 0 16:30:35 2662861383mS ISDNL3Evt: v=6 stacknum=6 State, new=DiscReq, old=Active id=5 16:30:35 2662861391mS ISDNL3Evt: v=6 stacknum=6 State, new=NullState, old=DiscReq id=5 16:30:35 2662861391mS CMLineRx: v=6 CMReleaseComp Line: type=Q931Line 6 Call: lid=6 id=5 in=1 BChan: slot=0 chan=3 16:30:35 2662861392mS CMCallEvt: c0a8000a00000005 6.5.1 -1 Q931 Trunk:6 CHAN=3: StateChange: END=X CMCSCompleted->CMCSDelete 16:30:35 2662861392mS CMTARGET: ISDN BChannel 3: in-service check = 1 16:30:35 2662861392mS CMTARGET: ISDN BChannel 3: in-service check = 1 16:30:35 2662861392mS CMCallEvt: c0a8000a00000005 6.5.1 -1 BaseEP: DELETE CMEndpoint f16afe10 TOTAL NOW=6 CALL_LIST=3 16:30:35 2662861860mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,361: Digit Key Pressed 1 16:30:35 2662861861mS CMExtnRx: v=361, p1=0 CMInformation Line: type=DigitalExtn 8 Call: lid=0 id=660859 in=0 Called[1] Type=Default (100) Reason=CMDRdirect Keypad[1] 16:30:35 2662861861mS CMTARGET: c0a8000a000a157b 0.660859.0 180673 jessenmacher.0: Setting Hard Timer 4000 16:30:35 2662861861mS CMTARGET: c0a8000a000a157b 0.660859.0 180673 jessenmacher.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=51 sub= calling=361 calling_sub= dir=out complete=0 ses=0 16:30:35 2662861862mS CMTARGET: c0a8000a000a157b 0.660859.0 180673 jessenmacher.0: ADD TARGET (N): number=51 type=100 depth=1 nobar=1 setorig=1 ses=0 16:30:36 2662862464mS H323Evt: Recv: RegistrationRequest 192.168.1.103; Extn(251), time since last RRQ-KA 55010, Endpoints registered: 13; Endpoints in registration: 0 ********** SysMonitor v9.1.6.0 build 153 [connected to 192.168.0.10 (Huron County)] ********** 16:30:36 2662862607mS PRN: Monitor Status IP 500 V2 9.1.6.0 build 153 16:30:36 2662862607mS PRN: LAW=U PRI=2, BRI=0, ALOG=4, VCOMP=10, MDM=0, WAN=0, MODU=5 LANM=0 CkSRC=5 VMAIL=1(VER=3 TYP=1) 1-X=0 CALLS=3(TOT=180673) 16:30:36 2662862706mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,361: Digit Key Pressed 2 16:30:36 2662862706mS CMExtnRx: v=361, p1=0 CMInformation Line: type=DigitalExtn 8 Call: lid=0 id=660859 in=0 Called[2] Type=Default (100) Reason=CMDRdirect Keypad[2] 16:30:36 2662862707mS CMTARGET: c0a8000a000a157b 0.660859.0 180673 jessenmacher.0: Setting Hard Timer 4000 16:30:36 2662862707mS CMTARGET: c0a8000a000a157b 0.660859.0 180673 jessenmacher.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=512 sub= calling=361 calling_sub= dir=out complete=0 ses=0 16:30:36 2662862707mS CMTARGET: c0a8000a000a157b 0.660859.0 180673 jessenmacher.0: ADD TARGET (N): number=512 type=100 depth=1 nobar=1 setorig=1 ses=0 16:30:37 2662863001mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,361: Digit Key Pressed 4 16:30:37 2662863002mS CMExtnRx: v=361, p1=0 CMInformation Line: type=DigitalExtn 8 Call: lid=0 id=660859 in=0 Called[4] Type=Default (100) Reason=CMDRdirect Keypad[4] 16:30:37 2662863002mS CMTARGET: c0a8000a000a157b 0.660859.0 180673 jessenmacher.0: Setting Hard Timer 4000 16:30:37 2662863002mS CMTARGET: c0a8000a000a157b 0.660859.0 180673 jessenmacher.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=5124 sub= calling=361 calling_sub= dir=out complete=0 ses=0 16:30:37 2662863003mS CMTARGET: c0a8000a000a157b 0.660859.0 180673 jessenmacher.0: ADD TARGET (N): number=5124 type=100 depth=1 nobar=1 setorig=1 ses=0 16:30:37 2662863377mS CMExtnEvt: dkidd: Recover Timer reason=CMTRWrapUp 16:30:37 2662863377mS CMExtnEvt: v=20 State, new=Idle old=PortRecoverDelay,0,0,dkidd 16:30:37 2662863377mS CMExtnTx: v=471, p1=0 CMVoiceMailStatus Line: type=DigitalExtn 9 Call: lid=0 id=-1 in=0 Called[dkidd Msgs=0 Old=1 Sav=0] Type=Default (100) Reason=CMDRdirect Calling[00000000] Type=Default Plan=Default Display [dkidd Msgs=0] Timed: 18/09/17 16:30 16:30:37 2662863617mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,361: Digit Key Pressed 8 16:30:37 2662863617mS CMExtnRx: v=361, p1=0 CMInformation Line: type=DigitalExtn 8 Call: lid=0 id=660859 in=0 Called[8] Type=Default (100) Reason=CMDRdirect Keypad[8] 16:30:37 2662863617mS CMTARGET: c0a8000a000a157b 0.660859.0 180673 jessenmacher.0: Setting Hard Timer 4000 16:30:37 2662863618mS CMTARGET: c0a8000a000a157b 0.660859.0 180673 jessenmacher.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=51248 sub= calling=361 calling_sub= dir=out complete=0 ses=0 16:30:37 2662863618mS CMTARGET: c0a8000a000a157b 0.660859.0 180673 jessenmacher.0: ADD TARGET (N): number=51248 type=100 depth=1 nobar=1 setorig=1 ses=0 16:30:38 2662864918mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,361: Digit Key Pressed 6 16:30:38 2662864918mS CMExtnRx: v=361, p1=0 CMInformation Line: type=DigitalExtn 8 Call: lid=0 id=660859 in=0 Called[6] Type=Default (100) Reason=CMDRdirect Keypad[6] 16:30:38 2662864919mS CMTARGET: c0a8000a000a157b 0.660859.0 180673 jessenmacher.0: Setting Hard Timer 4000 16:30:38 2662864919mS CMTARGET: c0a8000a000a157b 0.660859.0 180673 jessenmacher.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=512486 sub= calling=361 calling_sub= dir=out complete=0 ses=0 16:30:38 2662864919mS CMTARGET: c0a8000a000a157b 0.660859.0 180673 jessenmacher.0: ADD TARGET (N): number=512486 type=100 depth=1 nobar=1 setorig=1 ses=0 16:30:39 2662865593mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,361: Digit Key Pressed 2 16:30:39 2662865593mS CMExtnRx: v=361, p1=0 CMInformation Line: type=DigitalExtn 8 Call: lid=0 id=660859 in=0 Called[2] Type=Default (100) Reason=CMDRdirect Keypad[2] 16:30:39 2662865594mS CMTARGET: c0a8000a000a157b 0.660859.0 180673 jessenmacher.0: Setting Hard Timer 4000 16:30:39 2662865594mS CMTARGET: c0a8000a000a157b 0.660859.0 180673 jessenmacher.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=5124862 sub= calling=361 calling_sub= dir=out complete=0 ses=0 16:30:39 2662865594mS CMTARGET: c0a8000a000a157b 0.660859.0 180673 jessenmacher.0: ADD TARGET (N): number=5124862 type=100 depth=1 nobar=1 setorig=1 ses=0 16:30:39 2662866423mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,361: Digit Key Pressed 8 16:30:39 2662866423mS CMExtnRx: v=361, p1=0 CMInformation Line: type=DigitalExtn 8 Call: lid=0 id=660859 in=0 Called[8] Type=Default (100) Reason=CMDRdirect Keypad[8] 16:30:39 2662866424mS CMTARGET: c0a8000a000a157b 0.660859.0 180673 jessenmacher.0: Setting Hard Timer 4000 16:30:39 2662866424mS CMTARGET: c0a8000a000a157b 0.660859.0 180673 jessenmacher.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=51248628 sub= calling=361 calling_sub= dir=out complete=0 ses=0 16:30:39 2662866424mS CMTARGET: c0a8000a000a157b 0.660859.0 180673 jessenmacher.0: ADD TARGET (N): number=51248628 type=100 depth=1 nobar=1 setorig=1 ses=0 16:30:39 2662866998mS CMCallEvt: 0000000000000000 0.660861.0 -1 BaseEP: NEW CMEndpoint f4832b2c TOTAL NOW=7 CALL_LIST=3 16:30:39 2662866998mS CMCallEvt: 0000000000000000 0.660861.0 -1 kstacer.-1: NEW CMExtnEndpoint f4832b2c, Name=kstacer, Extn=481, Phys Extn=481 16:30:39 2662866998mS CMCallEvt: CREATE CALL:180674 (f4cf64d8) 16:30:39 2662866998mS CMCallEvt: 0000000000000000 0.660862.0 -1 BaseEP: NEW CMEndpoint f16436e4 TOTAL NOW=8 CALL_LIST=3 16:30:40 2662867000mS CMExtnEvt: kstacer: CMExtnHandler::SetCurrent( id: 0->660861 ) 16:30:40 2662867001mS CMExtnRx: v=481, p1=0 CMSetup Line: type=DigitalExtn 9 Call: lid=0 id=660861 in=0 Called[] Type=Default (100) Reason=CMDRdirect Calling[481] Type=Internal Plan=Default BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw IE CMIECallingPartyName (110)(Type=CMNameDefault) name=kstacer IE CMIECallingPartyKName (226)(Type=CMNameDefault) name=Keri Stacer 16:30:40 2662867001mS CMCallEvt: c0a8000a000a157d 0.660861.0 180674 kstacer.0: StateChange: END=A CMCSIdle->CMCSDialInitiated 16:30:40 2662867001mS CMExtnEvt: v=25 State, new=Dialling old=Idle,0,0,kstacer 16:30:40 2662867002mS CMTARGET: c0a8000a000a157d 0.660861.0 180674 kstacer.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party= sub= calling=481 calling_sub= dir=out complete=0 ses=0 16:30:40 2662867002mS CMTARGET: c0a8000a000a157d 0.660861.0 180674 kstacer.0: ADD TARGET (N): number= type=100 depth=1 nobar=1 setorig=1 ses=0 16:30:40 2662867003mS CMCallEvt: c0a8000a000a157d 0.660861.0 180674 kstacer.0: StateChange: END=A CMCSDialInitiated->CMCSDialling 16:30:40 2662867003mS CMExtnTx: v=481, p1=0 CMSetupAck Line: type=DigitalExtn 9 Call: lid=0 id=660861 in=0 BChan: slot=11 chan=27 Timed: 18/09/17 16:30 16:30:40 2662867005mS CD: CALL: 0.660861.0 BState=Idle Cut=1 Music=3.0 Aend="kstacer(481)" (11.27) Bend="" [] (0.0) CalledNum= () CallingNum=481 (kstacer) Internal=1 Time=7 AState=DialInitiated 16:30:40 2662867006mS CMMap: a=11.27 b=0.0 D1 16:30:40 2662867208mS RES: Mon 18/9/2017 16:30:40 FreeMem=47631516 Heap=45507632(1) Cache=2123884 MemObjs=34065(36418) CMMsg=8(9) ASN=0 Buff=5200 1353 1000 7362 5 Links=85191(85971) BTree=3359(6936) CPU=18.58% CPUStats=17.52%/9/15/144/11948/15010/00.52%/ 0/03.21% MCR=0 MCW=0 16:30:40 2662867208mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=52 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=100 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=50(TLS=5) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034 16:30:40 2662867209mS RES4: XML MemObjs=63 PoolMem=5796992(3) FreePoolMem=5781688(0) 16:30:40 2662867209mS RES5: CLog MemObjs=4866 FreePoolMem(Objs)=6968(134) TotalMem=704500 16:30:40 2662867780mS H323Evt: Recv: RegistrationRequest 192.168.1.106; Extn(254), time since last RRQ-KA 55013, Endpoints registered: 13; Endpoints in registration: 0 16:30:41 2662868119mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,481: Digit Key Pressed 5 16:30:41 2662868119mS CMExtnRx: v=481, p1=0 CMInformation Line: type=DigitalExtn 9 Call: lid=0 id=660861 in=0 Called[5] Type=Default (100) Reason=CMDRdirect Keypad[5] 16:30:41 2662868120mS CMTARGET: c0a8000a000a157d 0.660861.0 180674 kstacer.0: Setting Hard Timer 4000 16:30:41 2662868120mS CMTARGET: c0a8000a000a157d 0.660861.0 180674 kstacer.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=5 sub= calling=481 calling_sub= dir=out complete=0 ses=0 16:30:41 2662868120mS CMTARGET: c0a8000a000a157d 0.660861.0 180674 kstacer.0: ADD TARGET (N): number=5 type=100 depth=1 nobar=1 setorig=1 ses=0 16:30:41 2662868123mS CMMap: a=11.27 b=0.0 D0 16:30:41 2662868458mS SIP Rx: UDP 192.168.1.108:5060 -> 10.1.0.21:5060 OPTIONS sip:9892693555@192.168.1.108 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.108:5060;branch=z9hG4bKac2072610256 Max-Forwards: 70 From: ;tag=1c2072583065 To: Call-ID: 2072569481199201723050@192.168.1.108 CSeq: 1 OPTIONS Contact: Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE User-Agent: MP-124E FXS/v.6.60A.332.002 Accept: application/sdp, application/simple-message-summary, message/sipfrag Content-Length: 0 16:30:41 2662868463mS SIP Tx: UDP 10.1.0.21:5060 -> 192.168.1.108:5060 SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.1.108:5060;branch=z9hG4bKac2072610256 From: ;tag=1c2072583065 Call-ID: 2072569481199201723050@192.168.1.108 CSeq: 1 OPTIONS Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,INFO,REFER,NOTIFY,UPDATE Supported: timer Server: IP Office 9.1.6.0 build 153 To: ;tag=497af43d3554aed2 Content-Type: application/sdp Content-Length: 233 v=0 o=UserA 3211250258 1589096871 IN IP4 0.0.0.0 s=Session SDP c=IN IP4 0.0.0.0 t=0 0 m=audio 8000 RTP/AVP 0 8 18 4 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:4 G723/16000 16:30:41 2662868590mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,481: Digit Key Pressed 1 16:30:41 2662868591mS CMExtnRx: v=481, p1=0 CMInformation Line: type=DigitalExtn 9 Call: lid=0 id=660861 in=0 Called[1] Type=Default (100) Reason=CMDRdirect Keypad[1] 16:30:41 2662868591mS CMTARGET: c0a8000a000a157d 0.660861.0 180674 kstacer.0: Setting Hard Timer 4000 16:30:41 2662868591mS CMTARGET: c0a8000a000a157d 0.660861.0 180674 kstacer.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=51 sub= calling=481 calling_sub= dir=out complete=0 ses=0 16:30:41 2662868591mS CMTARGET: c0a8000a000a157d 0.660861.0 180674 kstacer.0: ADD TARGET (N): number=51 type=100 depth=1 nobar=1 setorig=1 ses=0 16:30:42 2662869198mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,481: Digit Key Pressed 9 16:30:42 2662869199mS CMExtnRx: v=481, p1=0 CMInformation Line: type=DigitalExtn 9 Call: lid=0 id=660861 in=0 Called[9] Type=Default (100) Reason=CMDRdirect Keypad[9] 16:30:42 2662869199mS CMTARGET: c0a8000a000a157d 0.660861.0 180674 kstacer.0: Setting Hard Timer 4000 16:30:42 2662869199mS CMTARGET: c0a8000a000a157d 0.660861.0 180674 kstacer.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=519 sub= calling=481 calling_sub= dir=out complete=0 ses=0 16:30:42 2662869199mS CMTARGET: c0a8000a000a157d 0.660861.0 180674 kstacer.0: ADD TARGET (N): number=519 type=100 depth=1 nobar=1 setorig=1 ses=0 16:30:42 2662869586mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,481: Digit Key Pressed 8 16:30:42 2662869586mS CMExtnRx: v=481, p1=0 CMInformation Line: type=DigitalExtn 9 Call: lid=0 id=660861 in=0 Called[8] Type=Default (100) Reason=CMDRdirect Keypad[8] 16:30:42 2662869587mS CMTARGET: c0a8000a000a157d 0.660861.0 180674 kstacer.0: Setting Hard Timer 4000 16:30:42 2662869587mS CMTARGET: c0a8000a000a157d 0.660861.0 180674 kstacer.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=5198 sub= calling=481 calling_sub= dir=out complete=0 ses=0 16:30:42 2662869587mS CMTARGET: c0a8000a000a157d 0.660861.0 180674 kstacer.0: ADD TARGET (N): number=5198 type=100 depth=1 nobar=1 setorig=1 ses=0 16:30:42 2662869963mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,361: Digit Key Pressed 2 16:30:42 2662869964mS CMExtnRx: v=361, p1=0 CMInformation Line: type=DigitalExtn 8 Call: lid=0 id=660859 in=0 Called[2] Type=Default (100) Reason=CMDRdirect Keypad[2] 16:30:42 2662869964mS CMTARGET: c0a8000a000a157b 0.660859.0 180673 jessenmacher.0: Setting Hard Timer 4000 16:30:42 2662869964mS CMTARGET: c0a8000a000a157b 0.660859.0 180673 jessenmacher.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=512486282 sub= calling=361 calling_sub= dir=out complete=0 ses=0 16:30:42 2662869964mS CMTARGET: c0a8000a000a157b 0.660859.0 180673 jessenmacher.0: ADD TARGET (N): number=512486282 type=100 depth=1 nobar=1 setorig=1 ses=0 16:30:43 2662870004mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,481: Digit Key Pressed 9 16:30:43 2662870004mS CMExtnRx: v=481, p1=0 CMInformation Line: type=DigitalExtn 9 Call: lid=0 id=660861 in=0 Called[9] Type=Default (100) Reason=CMDRdirect Keypad[9] 16:30:43 2662870005mS CMTARGET: c0a8000a000a157d 0.660861.0 180674 kstacer.0: Setting Hard Timer 4000 16:30:43 2662870005mS CMTARGET: c0a8000a000a157d 0.660861.0 180674 kstacer.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=51989 sub= calling=481 calling_sub= dir=out complete=0 ses=0 16:30:43 2662870005mS CMTARGET: c0a8000a000a157d 0.660861.0 180674 kstacer.0: ADD TARGET (N): number=51989 type=100 depth=1 nobar=1 setorig=1 ses=0 16:30:43 2662870244mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,361: Digit Key Pressed 5 16:30:43 2662870244mS CMExtnRx: v=361, p1=0 CMInformation Line: type=DigitalExtn 8 Call: lid=0 id=660859 in=0 Called[5] Type=Default (100) Reason=CMDRdirect Keypad[5] 16:30:43 2662870245mS CMTARGET: c0a8000a000a157b 0.660859.0 180673 jessenmacher.0: Setting Hard Timer 4000 16:30:43 2662870245mS CMTARGET: c0a8000a000a157b 0.660859.0 180673 jessenmacher.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=5124862825 sub= calling=361 calling_sub= dir=out complete=0 ses=0 16:30:43 2662870245mS CMTARGET: c0a8000a000a157b 0.660859.0 180673 jessenmacher.0: ADD TARGET (N): number=5124862825 type=100 depth=1 nobar=1 setorig=1 ses=0 16:30:43 2662870392mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,481: Digit Key Pressed 3 16:30:43 2662870393mS CMExtnRx: v=481, p1=0 CMInformation Line: type=DigitalExtn 9 Call: lid=0 id=660861 in=0 Called[3] Type=Default (100) Reason=CMDRdirect Keypad[3] 16:30:43 2662870393mS CMTARGET: c0a8000a000a157d 0.660861.0 180674 kstacer.0: Setting Hard Timer 4000 16:30:43 2662870393mS CMTARGET: c0a8000a000a157d 0.660861.0 180674 kstacer.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=519893 sub= calling=481 calling_sub= dir=out complete=0 ses=0 16:30:43 2662870393mS CMTARGET: c0a8000a000a157d 0.660861.0 180674 kstacer.0: ADD TARGET (N): number=519893 type=100 depth=1 nobar=1 setorig=1 ses=0 16:30:43 2662870711mS H323Evt: Recv: RegistrationRequest 192.168.1.105; Extn(253), time since last RRQ-KA 55011, Endpoints registered: 13; Endpoints in registration: 0 16:30:44 2662870715mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,361: Digit Key Pressed 6 16:30:44 2662870715mS CMExtnRx: v=361, p1=0 CMInformation Line: type=DigitalExtn 8 Call: lid=0 id=660859 in=0 Called[6] Type=Default (100) Reason=CMDRdirect Keypad[6] 16:30:44 2662870716mS CMTARGET: c0a8000a000a157b 0.660859.0 180673 jessenmacher.0: Setting Hard Timer 4000 16:30:44 2662870716mS CMTARGET: c0a8000a000a157b 0.660859.0 180673 jessenmacher.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=51248628256 sub= calling=361 calling_sub= dir=out complete=0 ses=0 16:30:44 2662870716mS CMTARGET: c0a8000a000a157b 0.660859.0 180673 jessenmacher.0: ADD TARGET (N): number=51248628256 type=100 depth=1 nobar=1 setorig=1 ses=0 16:30:44 2662870859mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,481: Digit Key Pressed 7 16:30:44 2662870860mS CMExtnRx: v=481, p1=0 CMInformation Line: type=DigitalExtn 9 Call: lid=0 id=660861 in=0 Called[7] Type=Default (100) Reason=CMDRdirect Keypad[7] 16:30:44 2662870860mS CMTARGET: c0a8000a000a157d 0.660861.0 180674 kstacer.0: Setting Hard Timer 4000 16:30:44 2662870860mS CMTARGET: c0a8000a000a157d 0.660861.0 180674 kstacer.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=5198937 sub= calling=481 calling_sub= dir=out complete=0 ses=0 16:30:44 2662870860mS CMTARGET: c0a8000a000a157d 0.660861.0 180674 kstacer.0: ADD TARGET (N): number=5198937 type=100 depth=1 nobar=1 setorig=1 ses=0 16:30:45 2662871075mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,361: Digit Key Pressed 1 16:30:45 2662871075mS CMExtnRx: v=361, p1=0 CMInformation Line: type=DigitalExtn 8 Call: lid=0 id=660859 in=0 Called[1] Type=Default (100) Reason=CMDRdirect Keypad[1] 16:30:45 2662871076mS CMTARGET: c0a8000a000a157b 0.660859.0 180673 jessenmacher.0: Setting Hard Timer 4000 16:30:45 2662871076mS CMTARGET: c0a8000a000a157b 0.660859.0 180673 jessenmacher.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=512486282561 sub= calling=361 calling_sub= dir=out complete=0 ses=0 16:30:45 2662871076mS CMTARGET: c0a8000a000a157b 0.660859.0 180673 jessenmacher.0: ADD TARGET (N): number=512486282561 type=100 depth=1 nobar=1 setorig=1 ses=0 16:30:45 2662871311mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,481: Digit Key Pressed 5 16:30:45 2662871311mS CMExtnRx: v=481, p1=0 CMInformation Line: type=DigitalExtn 9 Call: lid=0 id=660861 in=0 Called[5] Type=Default (100) Reason=CMDRdirect Keypad[5] 16:30:45 2662871312mS CMTARGET: c0a8000a000a157d 0.660861.0 180674 kstacer.0: Setting Hard Timer 4000 16:30:45 2662871312mS CMTARGET: c0a8000a000a157d 0.660861.0 180674 kstacer.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=51989375 sub= calling=481 calling_sub= dir=out complete=0 ses=0 16:30:45 2662871312mS CMTARGET: c0a8000a000a157d 0.660861.0 180674 kstacer.0: ADD TARGET (N): number=51989375 type=100 depth=1 nobar=1 setorig=1 ses=0 16:30:47 2662873304mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,481: Digit Key Pressed 4 16:30:47 2662873304mS CMExtnRx: v=481, p1=0 CMInformation Line: type=DigitalExtn 9 Call: lid=0 id=660861 in=0 Called[4] Type=Default (100) Reason=CMDRdirect Keypad[4] 16:30:47 2662873305mS CMTARGET: c0a8000a000a157d 0.660861.0 180674 kstacer.0: Setting Hard Timer 4000 16:30:47 2662873305mS CMTARGET: c0a8000a000a157d 0.660861.0 180674 kstacer.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=519893754 sub= calling=481 calling_sub= dir=out complete=0 ses=0 16:30:47 2662873305mS CMTARGET: c0a8000a000a157d 0.660861.0 180674 kstacer.0: ADD TARGET (N): number=519893754 type=100 depth=1 nobar=1 setorig=1 ses=0 16:30:47 2662873715mS RES: Mon 18/9/2017 16:30:47 FreeMem=47631492 Heap=45507632(1) Cache=2123860 MemObjs=34065(36418) CMMsg=8(9) ASN=0 Buff=5200 1353 1000 7362 5 Links=85189(85971) BTree=3359(6936) CPU=18.16% CPUStats=16.74%/1/5/144/12043/15010/00.47%/0 /03.21% MCR=0 MCW=0 16:30:47 2662873715mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=52 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=99 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=50(TLS=5) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034 16:30:47 2662873715mS RES4: XML MemObjs=63 PoolMem=5796992(3) FreePoolMem=5781688(0) 16:30:47 2662873715mS RES5: CLog MemObjs=4866 FreePoolMem(Objs)=6968(134) TotalMem=704500 16:30:47 2662873740mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,481: Digit Key Pressed 2 16:30:47 2662873740mS CMExtnRx: v=481, p1=0 CMInformation Line: type=DigitalExtn 9 Call: lid=0 id=660861 in=0 Called[2] Type=Default (100) Reason=CMDRdirect Keypad[2] 16:30:47 2662873741mS CMTARGET: c0a8000a000a157d 0.660861.0 180674 kstacer.0: Setting Hard Timer 4000 16:30:47 2662873741mS CMTARGET: c0a8000a000a157d 0.660861.0 180674 kstacer.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=5198937542 sub= calling=481 calling_sub= dir=out complete=0 ses=0 16:30:47 2662873741mS CMTARGET: c0a8000a000a157d 0.660861.0 180674 kstacer.0: ADD TARGET (N): number=5198937542 type=100 depth=1 nobar=1 setorig=1 ses=0 16:30:48 2662874303mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,481: Digit Key Pressed 9 16:30:48 2662874303mS CMExtnRx: v=481, p1=0 CMInformation Line: type=DigitalExtn 9 Call: lid=0 id=660861 in=0 Called[9] Type=Default (100) Reason=CMDRdirect Keypad[9] 16:30:48 2662874304mS CMTARGET: c0a8000a000a157d 0.660861.0 180674 kstacer.0: Setting Hard Timer 4000 16:30:48 2662874304mS CMTARGET: c0a8000a000a157d 0.660861.0 180674 kstacer.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=51989375429 sub= calling=481 calling_sub= dir=out complete=0 ses=0 16:30:48 2662874304mS CMTARGET: c0a8000a000a157d 0.660861.0 180674 kstacer.0: ADD TARGET (N): number=51989375429 type=100 depth=1 nobar=1 setorig=1 ses=0 16:30:48 2662874771mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,481: Digit Key Pressed 4 16:30:48 2662874772mS CMExtnRx: v=481, p1=0 CMInformation Line: type=DigitalExtn 9 Call: lid=0 id=660861 in=0 Called[4] Type=Default (100) Reason=CMDRdirect Keypad[4] 16:30:48 2662874772mS CMTARGET: c0a8000a000a157d 0.660861.0 180674 kstacer.0: Setting Hard Timer 4000 16:30:48 2662874772mS CMTARGET: c0a8000a000a157d 0.660861.0 180674 kstacer.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=519893754294 sub= calling=481 calling_sub= dir=out complete=0 ses=0 16:30:48 2662874773mS CMTARGET: c0a8000a000a157d 0.660861.0 180674 kstacer.0: ADD TARGET (N): number=519893754294 type=100 depth=1 nobar=1 setorig=1 ses=0 16:30:49 2662875076mS CMTARGET: c0a8000a000a157b 0.660859.0 180673 jessenmacher.0: TimerExpired cause=CMTCDelayedProcessing 16:30:49 2662875076mS CMTARGET: c0a8000a000a157b 0.660859.0 180673 jessenmacher.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=512486282561 sub= calling=361 calling_sub= dir=out complete=1 ses=0 16:30:49 2662875076mS CMTARGET: c0a8000a000a157b 0.660859.0 180673 jessenmacher.0: ADD TARGET (N): number=512486282561 type=100 depth=1 nobar=1 setorig=1 ses=0 16:30:49 2662875077mS CMTARGET: c0a8000a000a157b 0.660859.0 180673 jessenmacher.0: USER SC: 512486282561 3 12486282561 sc=type=Dial code=5N;, num=NSi9892698242 16:30:49 2662875077mS CMARS: FindActiveARSByGroupID GroupID=0 - Not Found 16:30:49 2662875077mS CMLRQ: FindActiveLRQByGroupID GroupID=0 - Not Found 16:30:49 2662875078mS CMCallEvt: 0000000000000000 0.660863.0 -1 BaseEP: NEW CMEndpoint f16afe10 TOTAL NOW=9 CALL_LIST=4 16:30:49 2662875078mS CMTARGET: ISDN BChannel 23: in-service check = 1 16:30:49 2662875078mS CMTARGET: ISDN BChannel 23: in-service check = 1 16:30:49 2662875080mS CMTARGET: DIAL LINE: 180673 GROUP = 0 SUCCESS = f16afe10 16:30:49 2662875080mS CMTARGET: c0a8000a000a157b 0.660859.0 180673 jessenmacher.0: INITIAL TARGETING SUCCEEDED 16:30:49 2662875080mS CMTARGET: c0a8000a000a157b 0.660859.0 180673 jessenmacher.0: GetNoAnswerTimer:15 16:30:49 2662875081mS CMCallEvt: c0a8000a000a157b 0.660859.0 180673 jessenmacher.0: StateChange: END=A CMCSDialling->CMCSDialled 16:30:49 2662875081mS CMExtnEvt: v=12 State, new=Proceeding old=Dialling,0,0,jessenmacher 16:30:49 2662875081mS CMExtnTx: v=361, p1=0 CMProceeding Line: type=DigitalExtn 8 Call: lid=0 id=660859 in=0 Timed: 18/09/17 16:30 16:30:49 2662875081mS CMCallEvt: 0000000000000000 0.660860.0 180673 TargetingEP: StateChange: END=B CMCSIdle->CMCSOffering 16:30:49 2662875082mS CMCallEvt: c0a8000a000a157f 0.660863.0 180673 Q931 Trunk:5 CHAN=23: StateChange: END=T CMCSIdle->CMCSOffering 16:30:49 2662875083mS PRN: Setting configured voice gain for ch 23. 16:30:49 2662875083mS CMLineTx: v=5 CMSetup Line: type=Q931Line 5 Call: lid=0 id=660863 in=0 Called[12486282561] Type=National (2) Reason=CMDRdirect Calling[9892698242] Type=National Plan=ISDN BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw BChan: slot=0 chan=23 Timed: 18/09/17 16:30 Locale: enu 16:30:49 2662875083mS CD: CALL: 0.660859.0 BState=Idle Cut=1 Music=0.0 Aend="jessenmacher(361)" (10.14) Bend="Line 5" [Line 5] (0.0) CalledNum=512486282561 () CallingNum=361 (jessenmacher) Internal=0 Time=14102 AState=Dialled 16:30:49 2662875085mS ISDNL3Evt: v=5 stacknum=5 State, new=Initiated, old=NullState id=660863 16:30:49 2662875107mS ISDNL3Evt: v=5 stacknum=5 State, new=Proceeding, old=Initiated id=660863 16:30:49 2662875108mS CMLineRx: v=5 CMProceeding Line: type=Q931Line 5 Call: lid=0 id=660863 in=0 BChan: slot=0 chan=23 16:30:49 2662875108mS CMCallEvt: 0000000000000000 0.660860.0 180673 TargetingEP: RequestEnd c0a8000a000a157f 0.660863.0 180673 Q931 Trunk:5 CHAN=23 16:30:49 2662875108mS CMTARGET: c0a8000a000a157b 0.660859.0 180673 jessenmacher.0: CancelTimer CMTCNoAnswerTimeout 16:30:49 2662875108mS CMCallEvt: 0000000000000000 0.660860.0 -1 BaseEP: DELETE CMEndpoint f171e7e8 TOTAL NOW=8 CALL_LIST=4 16:30:49 2662875109mS CMCallEvt: c0a8000a000a157f 0.660863.0 180673 Q931 Trunk:5 CHAN=23: StateChange: END=B CMCSOffering->CMCSAccept 16:30:49 2662875110mS CD: CALL: 0.660859.0 BState=Ringing Cut=3 Music=0.0 Aend="jessenmacher(361)" (10.14) Bend="Line 5" [Line 5] (3.24) CalledNum=12486282561 () CallingNum=361 (jessenmacher) Internal=0 Time=14129 AState=Dialled 16:30:49 2662875112mS CMMap: PCG::MapBChan pcp[191]b1r0 cp_b f4a5f998 other_cp_b 0 type CGTypeSimple 16:30:49 2662875112mS CMMap: PCG::MapBChan pcp[94]b1r0 cp_b f534dbc8 other_cp_b f4a5f998 type CGTypeSimple 16:30:49 2662875112mS CMMap: a=10.14 b=3.24 M12 16:30:52 2662878390mS H323Evt: Recv: RegistrationRequest 192.168.252.132; Extn(601), time since last RRQ-KA 55085, Endpoints registered: 13; Endpoints in registration: 0 16:30:52 2662878478mS H323Evt: Recv: RegistrationRequest 192.168.252.139; Extn(612), time since last RRQ-KA 55041, Endpoints registered: 13; Endpoints in registration: 0 16:30:52 2662878772mS CMTARGET: c0a8000a000a157d 0.660861.0 180674 kstacer.0: TimerExpired cause=CMTCDelayedProcessing 16:30:52 2662878773mS CMTARGET: c0a8000a000a157d 0.660861.0 180674 kstacer.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=519893754294 sub= calling=481 calling_sub= dir=out complete=1 ses=0 16:30:52 2662878773mS CMTARGET: c0a8000a000a157d 0.660861.0 180674 kstacer.0: ADD TARGET (N): number=519893754294 type=100 depth=1 nobar=1 setorig=1 ses=0 16:30:52 2662878773mS CMTARGET: c0a8000a000a157d 0.660861.0 180674 kstacer.0: USER SC: 519893754294 3 19893754294 sc=type=Dial code=5N;, num=NSi9892699255 16:30:52 2662878774mS CMARS: FindActiveARSByGroupID GroupID=0 - Not Found 16:30:52 2662878774mS CMLRQ: FindActiveLRQByGroupID GroupID=0 - Not Found 16:30:52 2662878775mS CMCallEvt: 0000000000000000 0.660864.0 -1 BaseEP: NEW CMEndpoint f47a2d98 TOTAL NOW=9 CALL_LIST=4 16:30:52 2662878775mS CMTARGET: ISDN BChannel 23: in-service check = 1 16:30:52 2662878775mS CMTARGET: ISDN BChannel 23: in-service check = 1 16:30:52 2662878777mS CMTARGET: DIAL LINE: 180674 GROUP = 0 SUCCESS = f47a2d98 16:30:52 2662878777mS CMTARGET: c0a8000a000a157d 0.660861.0 180674 kstacer.0: INITIAL TARGETING SUCCEEDED 16:30:52 2662878777mS CMTARGET: c0a8000a000a157d 0.660861.0 180674 kstacer.0: GetNoAnswerTimer:15 16:30:52 2662878778mS CMCallEvt: c0a8000a000a157d 0.660861.0 180674 kstacer.0: StateChange: END=A CMCSDialling->CMCSDialled 16:30:52 2662878778mS CMExtnEvt: v=25 State, new=Proceeding old=Dialling,0,0,kstacer 16:30:52 2662878778mS CMExtnTx: v=481, p1=0 CMProceeding Line: type=DigitalExtn 9 Call: lid=0 id=660861 in=0 Timed: 18/09/17 16:30 16:30:52 2662878779mS CMCallEvt: 0000000000000000 0.660862.0 180674 TargetingEP: StateChange: END=B CMCSIdle->CMCSOffering 16:30:52 2662878779mS CMCallEvt: c0a8000a000a1580 0.660864.0 180674 Q931 Trunk:6 CHAN=23: StateChange: END=T CMCSIdle->CMCSOffering 16:30:52 2662878780mS PRN: Setting configured voice gain for ch 23. 16:30:52 2662878780mS CMLineTx: v=6 CMSetup Line: type=Q931Line 6 Call: lid=0 id=660864 in=0 Called[19893754294] Type=National (2) Reason=CMDRdirect Calling[9892699255] Type=National Plan=ISDN BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw BChan: slot=0 chan=23 Timed: 18/09/17 16:30 Locale: enu 16:30:52 2662878780mS CD: CALL: 0.660861.0 BState=Idle Cut=1 Music=0.0 Aend="kstacer(481)" (11.27) Bend="Line 6" [Line 6] (0.0) CalledNum=519893754294 () CallingNum=481 (kstacer) Internal=0 Time=11782 AState=Dialled 16:30:52 2662878782mS ISDNL3Evt: v=6 stacknum=6 State, new=Initiated, old=NullState id=660864 16:30:52 2662878804mS ISDNL3Evt: v=6 stacknum=6 State, new=Proceeding, old=Initiated id=660864 16:30:52 2662878805mS CMLineRx: v=6 CMProceeding Line: type=Q931Line 6 Call: lid=0 id=660864 in=0 BChan: slot=0 chan=23 16:30:52 2662878805mS CMCallEvt: 0000000000000000 0.660862.0 180674 TargetingEP: RequestEnd c0a8000a000a1580 0.660864.0 180674 Q931 Trunk:6 CHAN=23 16:30:52 2662878806mS CMTARGET: c0a8000a000a157d 0.660861.0 180674 kstacer.0: CancelTimer CMTCNoAnswerTimeout 16:30:52 2662878806mS CMCallEvt: 0000000000000000 0.660862.0 -1 BaseEP: DELETE CMEndpoint f16436e4 TOTAL NOW=8 CALL_LIST=4 16:30:52 2662878806mS CMCallEvt: c0a8000a000a1580 0.660864.0 180674 Q931 Trunk:6 CHAN=23: StateChange: END=B CMCSOffering->CMCSAccept 16:30:52 2662878807mS CD: CALL: 0.660861.0 BState=Ringing Cut=3 Music=0.0 Aend="kstacer(481)" (11.27) Bend="Line 6" [Line 6] (3.56) CalledNum=19893754294 () CallingNum=481 (kstacer) Internal=0 Time=11809 AState=Dialled 16:30:52 2662878809mS CMMap: PCG::MapBChan pcp[245]b1r0 cp_b f4965280 other_cp_b 0 type CGTypeSimple 16:30:52 2662878809mS CMMap: PCG::MapBChan pcp[117]b1r0 cp_b f5211db4 other_cp_b f4965280 type CGTypeSimple 16:30:52 2662878809mS CMMap: a=11.27 b=3.56 M12 16:30:52 2662878925mS H323Evt: Recv: RegistrationRequest 192.168.252.136; Extn(606), time since last RRQ-KA 55056, Endpoints registered: 13; Endpoints in registration: 0 16:30:53 2662879222mS PRN: Optimizing BTree Lists Completed...Started:2662879220 Duration:1 Size:386 Attempted:386 16:30:53 2662879223mS RES: Mon 18/9/2017 16:30:52 FreeMem=47625332 Heap=45507632(1) Cache=2117700 MemObjs=34091(36418) CMMsg=8(9) ASN=0 Buff=5200 1353 999 7362 5 Links=85206(85971) BTree=3353(6936) CPU=17.97% CPUStats=19.18%/8/15/144/11865/15010/00.61%/0 /03.29% MCR=0 MCW=0 16:30:53 2662879224mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=52 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=98 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=50(TLS=5) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034 16:30:53 2662879224mS RES4: XML MemObjs=63 PoolMem=5796992(3) FreePoolMem=5781688(0) 16:30:53 2662879224mS RES5: CLog MemObjs=4866 FreePoolMem(Objs)=6968(134) TotalMem=704500 16:30:53 2662879858mS H323Evt: Recv: RegistrationRequest 192.168.252.134; Extn(604), time since last RRQ-KA 55042, Endpoints registered: 13; Endpoints in registration: 0 16:30:53 2662879918mS H323Evt: Recv: RegistrationRequest 192.168.1.104; Extn(252), time since last RRQ-KA 55011, Endpoints registered: 13; Endpoints in registration: 0 16:30:55 2662881786mS H323Evt: Recv: RegistrationRequest 192.168.252.138; Extn(611), time since last RRQ-KA 55047, Endpoints registered: 13; Endpoints in registration: 0 16:30:57 2662883075mS CMLineRx: v=6 CMProgress Line: type=Q931Line 6 Call: lid=0 id=660864 in=0 IE CMIEProgressIndicator (30) cs=CMCSITUT (0), loc=CMLPrivateNetLocalUser (1), pd=CMPDInbandPattern (8) 16:30:57 2662883075mS CMCallEvt: c0a8000a000a1580 0.660864.0 180674 Q931 Trunk:6 CHAN=23: StateChange: END=B CMCSAccept->CMCSRinging 16:30:57 2662883076mS CMCallEvt: c0a8000a000a157d 0.660861.0 180674 kstacer.0: StateChange: END=A CMCSDialled->CMCSRingBack 16:30:57 2662883077mS CMExtnEvt: v=25 State, new=Alerting old=Proceeding,0,0,kstacer 16:30:57 2662883077mS CMExtnTx: v=481, p1=0 CMProgress Line: type=DigitalExtn 9 Call: lid=0 id=660861 in=0 IE CMIEProgressIndicator (30) cs=CMCSITUT (0), loc=CMLPrivateNetLocalUser (1), pd=CMPDInbandPattern (8) IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=519893754294 IE CMIEDeviceDetail (231) c0a8000a000a1580 LOCALE=enu HW=15 VER=9 class=CMDeviceISDNTrunk type=2 number=6 channel=23 features=0x0 rx_gain=32 tx_gain=32 ep_callid=660864 ipaddr=192.168.0.10 apps=0 loc=0 em_loc=0 features2=0x0 is_spcall=1 Timed: 18/09/17 16:30 16:30:57 2662883078mS CD: CALL: 0.660861.0 BState=Ringing Cut=3 Music=0.0 Aend="kstacer(481)" (11.27) Bend="Line 6" [Line 6] (3.56) CalledNum=19893754294 () CallingNum=481 (kstacer) Internal=0 Time=16080 AState=Ringing 16:30:58 2662884648mS CMTARGET: ISDN BChannel 1: in-service check = 1 16:30:58 2662884648mS ISDNL3Evt: v=6 stacknum=6 State, new=Present, old=NullState id=22 16:30:58 2662884649mS CMLineRx: v=6 CMSetup Line: type=Q931Line 6 Call: lid=6 id=22 in=1 Called[912486282561] Type=Unknown (0) Reason=CMDRdirect SndComp Calling[519892698242] Type=Unknown Plan=ISDN Pres=Allowed (0) BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw BChan: slot=0 chan=1 16:30:58 2662884650mS PRN: Q931Trunk: Found QBChannel to match 0.1 --> 3.34 16:30:58 2662884650mS CMCallEvt: 0000000000000000 0.660865.0 -1 BaseEP: NEW CMEndpoint f17705c8 TOTAL NOW=9 CALL_LIST=4 16:30:58 2662884650mS CMTARGET: ISDN BChannel 1: in-service check = 1 16:30:58 2662884651mS CMTARGET: ISDN BChannel 1: in-service check = 1 16:30:58 2662884651mS CMCallEvt: CREATE CALL:180675 (f176ffc0) 16:30:58 2662884651mS CMCallEvt: 0000000000000000 0.660866.0 -1 BaseEP: NEW CMEndpoint f16436e4 TOTAL NOW=10 CALL_LIST=4 16:30:58 2662884654mS CD: CALL: 6.22.1 BState=Idle Cut=1 Music=0.0 Aend="Line 6" (3.34) Bend="" [] (0.0) CalledNum=912486282561 () CallingNum=519892698242 () Internal=0 Time=3 AState=Idle 16:30:58 2662884654mS CMCallEvt: c0a8000a00000016 6.22.1 180675 Q931 Trunk:6 CHAN=1: StateChange: END=A CMCSIdle->CMCSDialInitiated 16:30:58 2662884654mS CMTARGET: c0a8000a00000016 6.22.1 180675 Q931 Trunk:6 CHAN=1: LOOKUP CALL ROUTE: GID=0 type=0 called_party=912486282561 sub= calling=519892698242 calling_sub= dir=in complete=1 ses=0 16:30:58 2662884656mS CMLOGGING: CALL:2017/09/1816:30,00:00:00,000,519892698242,I,912486282561,912486282561,,,,0,,"",0,n/a 16:30:58 2662884657mS CD: CALL: 6.22.1 BState=Idle Cut=0 Music=0.0 Aend="Line 6" (3.34) Bend="" [] (0.0) CalledNum=912486282561 () CallingNum=519892698242 () Internal=0 Time=6 AState=Dialling 16:30:58 2662884657mS CD: CALL: 6.22.1 Deleted 16:30:58 2662884657mS CMLineTx: v=6 CMReleaseComp Line: type=Q931Line 6 Call: lid=6 id=22 in=1 Cause=88, Incompatible destination 16:30:58 2662884658mS CMCallEvt: c0a8000a00000016 6.22.1 -1 Q931 Trunk:6 CHAN=1: StateChange: END=X CMCSDialInitiated->CMCSDelete 16:30:58 2662884658mS CMCallEvt: 0000000000000000 0.660866.0 -1 BaseEP: DELETE CMEndpoint f16436e4 TOTAL NOW=9 CALL_LIST=4 16:30:58 2662884658mS CMCallEvt: END CALL:180675 (f176ffc0) 16:30:58 2662884659mS CMTARGET: ISDN BChannel 1: in-service check = 1 16:30:58 2662884659mS CMTARGET: ISDN BChannel 1: in-service check = 1 16:30:58 2662884659mS CMTARGET: c0a8000a00000016 6.22.1 -1 BaseEP: ~CMTargetHandler f179e5f0 ep f17705c8 16:30:58 2662884660mS CMCallEvt: c0a8000a00000016 6.22.1 -1 BaseEP: DELETE CMEndpoint f17705c8 TOTAL NOW=8 CALL_LIST=4 16:30:58 2662884662mS ISDNL3Evt: v=6 stacknum=6 State, new=NullState, old=Present id=22 16:30:58 2662884675mS ISDNL3Evt: v=5 stacknum=5 State, new=ReleaseReq, old=Proceeding id=660863 16:30:58 2662884682mS ISDNL3Evt: v=5 stacknum=5 State, new=NullState, old=ReleaseReq id=660863 16:30:58 2662884683mS CMLineRx: v=5 CMReleaseComp Line: type=Q931Line 5 Call: lid=0 id=660863 in=0 BChan: slot=0 chan=23 Cause=88, Incompatible destination 16:30:58 2662884683mS CMCallEvt: c0a8000a000a157f 0.660863.0 180673 Q931 Trunk:5 CHAN=23: StateChange: END=B CMCSAccept->CMCSCompleted 16:30:58 2662884685mS CMLOGGING: CALL:2017/09/1816:30,00:00:00,000,361,O,12486282561,512486282561,jessenmacher,,,0,,"",0,n/a 16:30:58 2662884685mS CD: CALL: 0.660859.0 BState=Disconnecting Cut=1 Music=0.0 Aend="jessenmacher(361)" (10.14) Bend="Line 5" [Line 5] (3.24) CalledNum=12486282561 () CallingNum=361 (jessenmacher) Internal=0 Time=23704 AState=Dialled 16:30:58 2662884686mS CD: CALL: 0.660859.0 Deleted 16:30:58 2662884686mS CMExtnEvt: jessenmacher: CALL LOST (CMCauseIncompatible) 16:30:58 2662884687mS CMExtnEvt: jessenmacher: Extn(361) Calling Party Number(361) Type(CMNTypeInternal) 16:30:58 2662884687mS CMCallEvt: c0a8000a000a157b 0.660859.0 -1 jessenmacher.0: StateChange: END=X CMCSDialled->CMCSCompletedTone 16:30:58 2662884687mS CMExtnEvt: v=12 State, new=CMESCompleted old=Proceeding,0,0,jessenmacher 16:30:58 2662884688mS CMCallEvt: c0a8000a000a157f 0.660863.0 -1 Q931 Trunk:5 CHAN=23: StateChange: END=X CMCSCompleted->CMCSDelete 16:30:58 2662884688mS CMCallEvt: END CALL:180673 (f1740e5c) 16:30:58 2662884689mS CMTARGET: ISDN BChannel 23: in-service check = 1 16:30:58 2662884689mS CMTARGET: ISDN BChannel 23: in-service check = 1 16:30:58 2662884690mS CMCallEvt: c0a8000a000a157f 0.660863.0 -1 BaseEP: DELETE CMEndpoint f16afe10 TOTAL NOW=7 CALL_LIST=3 16:30:58 2662884691mS CMMap: PCG::UnmapBChan pcp[191]b1r0 cp_b f4a5f998 other_cp_b f534dbc8 16:30:58 2662884691mS CMMap: a=3.24 b=10.14 M02 16:30:58 2662884691mS CMMap: PCG::UnmapBChan pcp[94]b1r0 cp_b f534dbc8 other_cp_b 0 16:30:58 2662884692mS CMMap: a=21.43 b=0.0 DTMF::AllocateRAS allocated CMRTVoicemail(f5396f70) resource busy 3, total 45 16:30:58 2662884692mS CMMap: a=21.43 b=1.65535 T 16:30:58 2662884693mS CMMap: a=21.43 b=10.14 M22 16:30:58 2662884726mS RES: Mon 18/9/2017 16:30:58 FreeMem=47640456 Heap=45507632(1) Cache=2132824 MemObjs=34059(36418) CMMsg=8(9) ASN=0 Buff=5200 1337 1000 7361 5 Links=85216(85971) BTree=3353(6936) CPU=17.76% CPUStats=18.40%/1/5/144/12079/15010/00.50%/0 /03.23% MCR=0 MCW=0 16:30:58 2662884726mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=52 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=107 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=50(TLS=5) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034 16:30:58 2662884726mS RES4: XML MemObjs=63 PoolMem=5796992(3) FreePoolMem=5781688(0) 16:30:58 2662884726mS RES5: CLog MemObjs=4866 FreePoolMem(Objs)=6968(134) TotalMem=704500 16:30:59 2662885388mS H323Evt: Recv: RegistrationRequest 192.168.252.133; Extn(495), time since last RRQ-KA 55041, Endpoints registered: 13; Endpoints in registration: 0 16:30:59 2662885405mS H323Evt: Recv: RegistrationRequest 192.168.252.137; Extn(609), time since last RRQ-KA 55041, Endpoints registered: 13; Endpoints in registration: 0 16:30:59 2662885415mS H323Evt: Recv: RegistrationRequest 192.168.252.135; Extn(605), time since last RRQ-KA 55041, Endpoints registered: 13; Endpoints in registration: 0 16:31:00 2662886566mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,361: Menu Key Pressed 12:I 16:31:00 2662886567mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,361: Feature Key Pressed 6:DCPLFeatureDrop 16:31:00 2662886567mS CMExtnEvt: jessenmacher: CMExtnHandler::SetCurrent( id: 660859->0 ) 16:31:00 2662886568mS CMExtnTx: v=361, p1=0 CMReleaseComp Line: type=DigitalExtn 8 Call: lid=0 id=660859 in=0 Called[512486282561] Type=Default (100) Reason=CMDRdirect Calling[361] Type=Internal Plan=Default Cause=2, No route to specific transit network/(5ESS)Calling party off hold Timed: 18/09/17 16:30 16:31:00 2662886568mS CMCallEvt: c0a8000a000a157b 0.660859.0 -1 jessenmacher.-1: StateChange: END=X CMCSCompletedTone->CMCSDelete 16:31:00 2662886568mS CMExtnEvt: v=12 State, new=PortRecoverDelay old=CMESCompleted,0,0,jessenmacher 16:31:00 2662886569mS CMTARGET: c0a8000a000a157b 0.660859.0 -1 BaseEP: ~CMTargetHandler f1717bbc ep f48291a8 16:31:00 2662886569mS CMCallEvt: c0a8000a000a157b 0.660859.0 -1 BaseEP: DELETE CMEndpoint f48291a8 TOTAL NOW=6 CALL_LIST=3 16:31:00 2662886572mS CMMap: a=21.43 b=10.14 M02 16:31:00 2662886572mS CMMap: a=21.43 b=0.0 T0 16:31:00 2662886573mS CMMap: a=21.43 b=0.0 DTMF::~DTMF freed CMRTUnknown(f5396f70) resource busy 2, total 45 16:31:02 2662888044mS H323Evt: Recv: RegistrationRequest 192.168.1.102; Extn(250), time since last RRQ-KA 55010, Endpoints registered: 13; Endpoints in registration: 0 16:31:02 2662888568mS CMExtnEvt: jessenmacher: Recover Timer reason=CMTRWrapUp 16:31:02 2662888568mS CMExtnEvt: v=12 State, new=Idle old=PortRecoverDelay,0,0,jessenmacher 16:31:02 2662888569mS CMExtnTx: v=361, p1=0 CMVoiceMailStatus Line: type=DigitalExtn 8 Call: lid=0 id=-1 in=0 Called[jessenmacher Msgs=0 Old=0 Sav=15] Type=Default (100) Reason=CMDRdirect Calling[00000000] Type=Default Plan=Default Display [jessenmacher Msgs=0] Timed: 18/09/17 16:31 16:31:06 2662892614mS SIP Rx: UDP 192.168.1.108:5060 -> 10.1.0.21:5060 BYE sip:anonymous@10.1.0.21:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.108:5060;branch=z9hG4bKac227054576 Max-Forwards: 70 From: ;tag=1c1045419158 To: "Anonymous" ;tag=29d3798ea46f02c3 Call-ID: eec0c3697c28352ec6bea8fc3c37aec8 CSeq: 1 BYE Supported: em,timer,replaces,path,resource-priority Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE User-Agent: MP-124E FXS/v.6.60A.332.002 Reason: Q.850 ;cause=16 ;text="local" Content-Length: 0 16:31:06 2662892618mS SIP Tx: UDP 10.1.0.21:5060 -> 192.168.1.108:5060 SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.1.108:5060;branch=z9hG4bKac227054576 From: ;tag=1c1045419158 Call-ID: eec0c3697c28352ec6bea8fc3c37aec8 CSeq: 1 BYE Supported: timer Server: IP Office 9.1.6.0 build 153 To: "Anonymous" ;tag=29d3798ea46f02c3 Content-Length: 0 16:31:06 2662892619mS CMLineRx: v=0 CMReleaseComp Line: type=SIPLine 17 Call: lid=17 id=660850 in=0 IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=9892696421 IE CMIEDeviceDetail (231) c0a8000a000a1572 LOCALE=enu HW=15 VER=9 class=CMDeviceSIPTrunk type=0 number=17 channel=1 features=0x0 rx_gain=32 tx_gain=32 ep_callid=660850 ipaddr=192.168.0.10 apps=0 loc=999 em_loc=999 features2=0x0 is_spcall=1 Cause=16, Normal call clearing 16:31:06 2662892619mS CMCallEvt: c0a8000a000a1572 17.660850.0 180669 SIPTrunk Endpoint: StateChange: END=B CMCSConnected->CMCSCompleted 16:31:06 2662892621mS CMLOGGING: CALL:2017/09/1816:29,00:01:42,003,,I,9892696421,9892696421,Anonymous,,,0,,"",0,n/a 16:31:06 2662892622mS CD: CALL: 5.13.1 BState=Disconnecting Cut=1 Music=0.0 Aend="Line 5" (3.2) Bend="Line 17" [Line 17] (0.0) CalledNum=9892696421 () CallingNum= (WITHHELD) Internal=0 Time=106399 AState=Connected 16:31:06 2662892622mS CD: CALL: 5.13.1 Deleted 16:31:06 2662892623mS CMLineTx: v=5 CMDisconnect Line: type=Q931Line 5 Call: lid=5 id=13 in=1 Cause=16, Normal call clearing 16:31:06 2662892624mS CMCallEvt: c0a8000a0000000d 5.13.1 -1 Q931 Trunk:5 CHAN=1: StateChange: END=X CMCSConnected->CMCSCompleted 16:31:06 2662892624mS CMCallEvt: c0a8000a000a1572 17.660850.0 -1 SIPTrunk Endpoint: StateChange: END=X CMCSCompleted->CMCSDelete 16:31:06 2662892624mS CMCallEvt: END CALL:180669 (f16b82e8) 16:31:06 2662892626mS CMCallEvt: c0a8000a000a1572 17.660850.0 -1 BaseEP: DELETE CMEndpoint f168e830 TOTAL NOW=5 CALL_LIST=2 16:31:06 2662892628mS CMMap: PCG::UnmapBChan pcp[72]b1r0 cp_b f5351fd8 other_cp_b f53a088c 16:31:06 2662892628mS CMMap: a=0.18 b=3.2 M02 16:31:06 2662892628mS CMMap: PlatformConnectionAudioSAP::DisconnectRtpFilter rtpRelay ID: 1 Close success 16:31:06 2662892629mS H323Evt: SESS 61a6 SetOperational local 10.1.0.21:46750 remote 192.168.1.108:6100 to 0 16:31:06 2662892629mS CMMap: PCG::UnmapBChan pcp[738]b0r1 cp_b 0 other_cp_b 0 16:31:06 2662892629mS H323Evt: SESS 61a6: RTP(END): 10.1.0.21/46750 192.168.1.108/6100 CODEC=Ulaw64K(5) PKTSZ=160 RFC2833=on AGE=102410 SENT=5108 RECV=5122 RTdelay=0 jitter=0 loss=0 remotejitter=0 remoteloss=0 16:31:06 2662892630mS CMMap: a=0.18 b=0.0 Mapper::FreeCodec freed CMRTVocoder(f53bd1f4) resource busy 1, total 10 16:31:06 2662892633mS ISDNL3Evt: v=5 stacknum=5 State, new=DiscReq, old=Active id=13 16:31:06 2662892641mS ISDNL3Evt: v=5 stacknum=5 State, new=NullState, old=DiscReq id=13 16:31:06 2662892642mS CMLineRx: v=5 CMReleaseComp Line: type=Q931Line 5 Call: lid=5 id=13 in=1 BChan: slot=0 chan=1 16:31:06 2662892642mS CMCallEvt: c0a8000a0000000d 5.13.1 -1 Q931 Trunk:5 CHAN=1: StateChange: END=X CMCSCompleted->CMCSDelete 16:31:06 2662892642mS CMTARGET: ISDN BChannel 1: in-service check = 1 16:31:06 2662892642mS CMTARGET: ISDN BChannel 1: in-service check = 1 16:31:06 2662892643mS CMCallEvt: c0a8000a0000000d 5.13.1 -1 BaseEP: DELETE CMEndpoint f4818aac TOTAL NOW=4 CALL_LIST=2 16:31:06 2662892739mS RES: Mon 18/9/2017 16:31:06 FreeMem=47666064 Heap=45474844(1) Cache=2191220 MemObjs=33768(36418) CMMsg=8(9) ASN=0 Buff=5200 1353 1000 7363 5 Links=85100(85971) BTree=3351(6936) CPU=17.88% CPUStats=17.03%/1/5/144/12232/15010/00.46%/1 /03.19% MCR=0 MCW=0 16:31:06 2662892739mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=52 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=96 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=50(TLS=5) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034 16:31:06 2662892740mS RES4: XML MemObjs=63 PoolMem=5796992(3) FreePoolMem=5781688(0) 16:31:06 2662892740mS RES5: CLog MemObjs=4866 FreePoolMem(Objs)=6968(134) TotalMem=704500 16:31:11 2662897745mS RES: Mon 18/9/2017 16:31:11 FreeMem=47702528 Heap=45507632(1) Cache=2194896 MemObjs=33690(36418) CMMsg=8(9) ASN=0 Buff=5200 1353 1000 7363 5 Links=85098(85971) BTree=3351(6936) CPU=17.78% CPUStats=16.94%/1/5/144/12235/15010/00.16%/1 /02.80% MCR=0 MCW=0 16:31:11 2662897745mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=52 RTEngine=1 CMRTEngine=0 ExRTEngine=0 Timer=95 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=50(TLS=5) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034 16:31:11 2662897745mS RES4: XML MemObjs=63 PoolMem=5796992(3) FreePoolMem=5781688(0) 16:31:11 2662897745mS RES5: CLog MemObjs=4866 FreePoolMem(Objs)=6968(134) TotalMem=704500 16:31:17 2662903273mS CMLineRx: v=6 CMProgress Line: type=Q931Line 6 Call: lid=0 id=660864 in=0 IE CMIEProgressIndicator (30) cs=CMCSITUT (0), loc=CMLPrivateNetLocalUser (1), pd=CMPDInbandPattern (8) 16:31:17 2662903274mS CMExtnTx: v=481, p1=0 CMProgress Line: type=DigitalExtn 9 Call: lid=0 id=660861 in=0 IE CMIEProgressIndicator (30) cs=CMCSITUT (0), loc=CMLPrivateNetLocalUser (1), pd=CMPDInbandPattern (8) IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=519893754294 IE CMIEDeviceDetail (231) c0a8000a000a1580 LOCALE=enu HW=15 VER=9 class=CMDeviceISDNTrunk type=2 number=6 channel=23 features=0x0 rx_gain=32 tx_gain=32 ep_callid=660864 ipaddr=192.168.0.10 apps=0 loc=0 em_loc=0 features2=0x0 is_spcall=1 Timed: 18/09/17 16:31 16:31:17 2662903274mS CD: CALL: 0.660861.0 BState=Ringing Cut=3 Music=0.0 Aend="kstacer(481)" (11.27) Bend="Line 6" [Line 6] (3.56) CalledNum=19893754294 () CallingNum=481 (kstacer) Internal=0 Time=36276 AState=Ringing 16:31:17 2662903916mS CMLineRx: v=6 CMProgress Line: type=Q931Line 6 Call: lid=0 id=660864 in=0 IE CMIEProgressIndicator (30) cs=CMCSITUT (0), loc=CMLPrivateNetLocalUser (1), pd=CMPDInbandPattern (8) 16:31:17 2662903917mS CMExtnTx: v=481, p1=0 CMProgress Line: type=DigitalExtn 9 Call: lid=0 id=660861 in=0 IE CMIEProgressIndicator (30) cs=CMCSITUT (0), loc=CMLPrivateNetLocalUser (1), pd=CMPDInbandPattern (8) IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=519893754294 IE CMIEDeviceDetail (231) c0a8000a000a1580 LOCALE=enu HW=15 VER=9 class=CMDeviceISDNTrunk type=2 number=6 channel=23 features=0x0 rx_gain=32 tx_gain=32 ep_callid=660864 ipaddr=192.168.0.10 apps=0 loc=0 em_loc=0 features2=0x0 is_spcall=1 Timed: 18/09/17 16:31 16:31:17 2662903917mS CD: CALL: 0.660861.0 BState=Ringing Cut=3 Music=0.0 Aend="kstacer(481)" (11.27) Bend="Line 6" [Line 6] (3.56) CalledNum=19893754294 () CallingNum=481 (kstacer) Internal=0 Time=36919 AState=Ringing 16:31:17 2662903919mS ISDNL3Evt: v=6 stacknum=6 State, new=Active, old=Proceeding id=660864 16:31:17 2662903920mS CMLineRx: v=6 CMConnect Line: type=Q931Line 6 Call: lid=0 id=660864 in=0 IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:0 R:4) number=51?19893754294 16:31:17 2662903921mS CMCallEvt: c0a8000a000a1580 0.660864.0 180674 Q931 Trunk:6 CHAN=23: StateChange: END=B CMCSRinging->CMCSConnReq 16:31:17 2662903921mS CMCallEvt: c0a8000a000a157d 0.660861.0 180674 kstacer.0: StateChange: END=A CMCSRingBack->CMCSOGConnReq 16:31:17 2662903921mS CMExtnEvt: v=25 State, new=Connected old=Alerting,0,0,kstacer 16:31:17 2662903921mS CMExtnTx: v=481, p1=0 CMConnect Line: type=DigitalExtn 9 Call: lid=0 id=660861 in=0 IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=519893754294 IE CMIEDeviceDetail (231) c0a8000a000a1580 LOCALE=enu HW=15 VER=9 class=CMDeviceISDNTrunk type=2 number=6 channel=23 features=0x0 rx_gain=32 tx_gain=32 ep_callid=660864 ipaddr=192.168.0.10 apps=0 loc=0 em_loc=0 features2=0x0 is_spcall=1 Timed: 18/09/17 16:31 16:31:17 2662903922mS CMExtnRx: v=481, p1=0 CMConnectAck Line: type=DigitalExtn 9 Call: lid=0 id=660861 in=0 16:31:17 2662903922mS CMCallEvt: c0a8000a000a157d 0.660861.0 180674 kstacer.0: StateChange: END=A CMCSOGConnReq->CMCSConnected 16:31:17 2662903922mS CMTARGET: c0a8000a000a157d 0.660861.0 180674 kstacer.0: ~CMTargetHandler f1749e0c ep f4832b2c 16:31:17 2662903923mS CMCallEvt: c0a8000a000a1580 0.660864.0 180674 Q931 Trunk:6 CHAN=23: StateChange: END=B CMCSConnReq->CMCSConnected 16:31:17 2662903924mS CMLineTx: v=6 CMConnectAck Line: type=Q931Line 6 Call: lid=0 id=660864 in=0 BChan: slot=0 chan=23 16:31:17 2662903924mS CD: CALL: 0.660861.0 BState=Connected Cut=3 Music=0.0 Aend="kstacer(481)" (11.27) Bend="Line 6" [Line 6] (3.56) CalledNum=19893754294 () CallingNum=481 (kstacer) Internal=0 Time=36926 AState=Connected 16:31:18 2662904247mS RES: Mon 18/9/2017 16:31:17 FreeMem=47708732 Heap=45507632(1) Cache=2201100 MemObjs=33697(36418) CMMsg=8(9) ASN=0 Buff=5200 1353 1000 7363 5 Links=85100(85971) BTree=3351(6936) CPU=17.61% CPUStats=18.79%/5/14/144/12127/15010/00.35%/ 1/02.78% MCR=0 MCW=0 16:31:18 2662904248mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=52 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=98 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=50(TLS=5) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034 16:31:18 2662904248mS RES4: XML MemObjs=63 PoolMem=5796992(3) FreePoolMem=5781688(0) 16:31:18 2662904248mS RES5: CLog MemObjs=4866 FreePoolMem(Objs)=6968(134) TotalMem=704500 16:31:30 2662917475mS H323Evt: Recv: RegistrationRequest 192.168.1.103; Extn(251), time since last RRQ-KA 55011, Endpoints registered: 13; Endpoints in registration: 0 16:31:34 2662921380mS CMExtnEvt: dkidd: No user activity ********** SysMonitor v9.1.6.0 build 153 [connected to 192.168.0.10 (Huron County)] ********** 16:31:35 2662922603mS PRN: Monitor Status IP 500 V2 9.1.6.0 build 153 16:31:35 2662922603mS PRN: LAW=U PRI=2, BRI=0, ALOG=4, VCOMP=10, MDM=0, WAN=0, MODU=5 LANM=0 CkSRC=5 VMAIL=1(VER=3 TYP=1) 1-X=0 CALLS=2(TOT=180675) 16:31:35 2662922791mS H323Evt: Recv: RegistrationRequest 192.168.1.106; Extn(254), time since last RRQ-KA 55011, Endpoints registered: 13; Endpoints in registration: 0 16:31:38 2662925723mS H323Evt: Recv: RegistrationRequest 192.168.1.105; Extn(253), time since last RRQ-KA 55012, Endpoints registered: 13; Endpoints in registration: 0 16:31:41 2662928538mS SIP Rx: UDP 192.168.1.108:5060 -> 10.1.0.21:5060 OPTIONS sip:9892693555@192.168.1.108 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.108:5060;branch=z9hG4bKac676051155 Max-Forwards: 70 From: ;tag=1c676024698 To: Call-ID: 676020752199201723150@192.168.1.108 CSeq: 1 OPTIONS Contact: Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE User-Agent: MP-124E FXS/v.6.60A.332.002 Accept: application/sdp, application/simple-message-summary, message/sipfrag Content-Length: 0 16:31:41 2662928543mS SIP Tx: UDP 10.1.0.21:5060 -> 192.168.1.108:5060 SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.1.108:5060;branch=z9hG4bKac676051155 From: ;tag=1c676024698 Call-ID: 676020752199201723150@192.168.1.108 CSeq: 1 OPTIONS Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,INFO,REFER,NOTIFY,UPDATE Supported: timer Server: IP Office 9.1.6.0 build 153 To: ;tag=6071ff8ca02b7905 Content-Type: application/sdp Content-Length: 233 v=0 o=UserA 2526820587 2362795580 IN IP4 0.0.0.0 s=Session SDP c=IN IP4 0.0.0.0 t=0 0 m=audio 8000 RTP/AVP 0 8 18 4 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:4 G723/16000 16:31:41 2662928669mS RES: Mon 18/9/2017 16:31:42 FreeMem=47663520 Heap=45474844(1) Cache=2188676 MemObjs=33833(36418) CMMsg=8(9) ASN=0 Buff=5200 1353 1000 7363 5 Links=85102(85971) BTree=3351(6936) CPU=17.66% CPUStats=16.84%/1/4/144/12350/15010/00.09%/0 /02.76% MCR=0 MCW=0 16:31:41 2662928669mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=52 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=95 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=50(TLS=5) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034 16:31:41 2662928669mS RES4: XML MemObjs=63 PoolMem=5796992(3) FreePoolMem=5781688(0) 16:31:41 2662928669mS RES5: CLog MemObjs=4866 FreePoolMem(Objs)=6968(134) TotalMem=704500 16:31:46 2662933431mS H323Evt: Recv: RegistrationRequest 192.168.252.132; Extn(601), time since last RRQ-KA 55041, Endpoints registered: 13; Endpoints in registration: 0 16:31:46 2662933520mS H323Evt: Recv: RegistrationRequest 192.168.252.139; Extn(612), time since last RRQ-KA 55042, Endpoints registered: 13; Endpoints in registration: 0 16:31:46 2662933671mS RES: Mon 18/9/2017 16:31:47 FreeMem=47708732 Heap=45507632(1) Cache=2201100 MemObjs=33697(36418) CMMsg=8(9) ASN=0 Buff=5200 1353 1000 7364 5 Links=85101(85971) BTree=3351(6936) CPU=17.52% CPUStats=17.33%/1/5/144/12299/15010/00.15%/0 /02.79% MCR=0 MCW=0 16:31:46 2662933671mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=52 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=94 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=50(TLS=5) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034 16:31:46 2662933671mS RES4: XML MemObjs=63 PoolMem=5796992(3) FreePoolMem=5781688(0) 16:31:46 2662933671mS RES5: CLog MemObjs=4866 FreePoolMem(Objs)=6968(134) TotalMem=704500 16:31:46 2662933972mS H323Evt: Recv: RegistrationRequest 192.168.252.136; Extn(606), time since last RRQ-KA 55047, Endpoints registered: 13; Endpoints in registration: 0 16:31:47 2662934771mS CMExtnEvt: kstacer: No user activity 16:31:47 2662934900mS H323Evt: Recv: RegistrationRequest 192.168.252.134; Extn(604), time since last RRQ-KA 55042, Endpoints registered: 13; Endpoints in registration: 0 16:31:47 2662934929mS H323Evt: Recv: RegistrationRequest 192.168.1.104; Extn(252), time since last RRQ-KA 55011, Endpoints registered: 13; Endpoints in registration: 0 16:31:49 2662936829mS H323Evt: Recv: RegistrationRequest 192.168.252.138; Extn(611), time since last RRQ-KA 55043, Endpoints registered: 13; Endpoints in registration: 0 16:31:52 2662939223mS PRN: Optimizing BTree Lists Completed...Started:2662939222 Duration:1 Size:382 Attempted:382 16:31:53 2662940431mS H323Evt: Recv: RegistrationRequest 192.168.252.133; Extn(495), time since last RRQ-KA 55042, Endpoints registered: 13; Endpoints in registration: 0 16:31:53 2662940447mS H323Evt: Recv: RegistrationRequest 192.168.252.137; Extn(609), time since last RRQ-KA 55042, Endpoints registered: 13; Endpoints in registration: 0 16:31:53 2662940456mS H323Evt: Recv: RegistrationRequest 192.168.252.135; Extn(605), time since last RRQ-KA 55041, Endpoints registered: 13; Endpoints in registration: 0 16:31:54 2662941362mS PRN: Config Write Wake Up 16:31:54 2662941862mS PRN: Updates IO list size 1 updated list size 7 16:31:54 2662941862mS PRN: Sending Updates out to f497c45c started 16:31:54 2662941863mS PRN: Sending Updates out to f497c45c finished 16:31:54 2662941864mS PRN: Config Write Completed 16:31:56 2662943060mS H323Evt: Recv: RegistrationRequest 192.168.1.102; Extn(250), time since last RRQ-KA 55016, Endpoints registered: 13; Endpoints in registration: 0 16:31:57 2662944994mS CMExtnRx: v=481, p1=0 CMReleaseComp Line: type=DigitalExtn 9 Call: lid=0 id=660861 in=0 16:31:57 2662944994mS CMCallEvt: c0a8000a000a157d 0.660861.0 180674 kstacer.0: StateChange: END=A CMCSConnected->CMCSCompleted 16:31:57 2662944995mS CMExtnEvt: v=25 State, new=PortRecoverDelay old=Connected,0,0,kstacer 16:31:57 2662944996mS CMLOGGING: CALL:2017/09/1816:30,00:00:41,000,481,O,19893754294,519893754294,kstacer,,,0,,"",0,n/a 16:31:57 2662944997mS CD: CALL: 0.660861.0 BState=Connected Cut=2 Music=0.0 Aend="kstacer(481)" (11.27) Bend="Line 6" [Line 6] (3.56) CalledNum=19893754294 () CallingNum=481 (kstacer) Internal=0 Time=77999 AState=Idle 16:31:57 2662944997mS CD: CALL: 0.660861.0 Deleted 16:31:57 2662944997mS CMExtnEvt: kstacer: CALL LOST (CMCauseNormal) 16:31:57 2662944997mS CMExtnEvt: kstacer: Extn(481) Calling Party Number(481) Type(CMNTypeInternal) 16:31:57 2662944998mS CMExtnEvt: kstacer: CMExtnHandler::SetCurrent( id: 660861->0 ) 16:31:57 2662944998mS CMCallEvt: c0a8000a000a157d 0.660861.0 -1 kstacer.-1: StateChange: END=X CMCSCompleted->CMCSDelete 16:31:57 2662944999mS CMLineTx: v=6 CMDisconnect Line: type=Q931Line 6 Call: lid=0 id=660864 in=0 Cause=16, Normal call clearing 16:31:58 2662945000mS CMCallEvt: c0a8000a000a1580 0.660864.0 -1 Q931 Trunk:6 CHAN=23: StateChange: END=X CMCSConnected->CMCSCompleted 16:31:58 2662945000mS CMCallEvt: END CALL:180674 (f4cf64d8) 16:31:58 2662945000mS CMCallEvt: c0a8000a000a157d 0.660861.0 -1 BaseEP: DELETE CMEndpoint f4832b2c TOTAL NOW=3 CALL_LIST=1 16:31:58 2662945004mS CMMap: PCG::UnmapBChan pcp[117]b1r0 cp_b f5211db4 other_cp_b f4965280 16:31:58 2662945004mS CMMap: a=11.27 b=3.56 M02 16:31:58 2662945004mS CMMap: PCG::UnmapBChan pcp[245]b1r0 cp_b f4965280 other_cp_b 0 16:31:58 2662945005mS ISDNL3Evt: v=6 stacknum=6 State, new=DiscReq, old=Active id=660864 16:31:58 2662945013mS ISDNL3Evt: v=6 stacknum=6 State, new=NullState, old=DiscReq id=660864 16:31:58 2662945014mS CMLineRx: v=6 CMReleaseComp Line: type=Q931Line 6 Call: lid=0 id=660864 in=0 BChan: slot=0 chan=23 16:31:58 2662945014mS CMCallEvt: c0a8000a000a1580 0.660864.0 -1 Q931 Trunk:6 CHAN=23: StateChange: END=X CMCSCompleted->CMCSDelete 16:31:58 2662945014mS CMTARGET: ISDN BChannel 23: in-service check = 1 16:31:58 2662945014mS CMTARGET: ISDN BChannel 23: in-service check = 1 16:31:58 2662945015mS CMCallEvt: c0a8000a000a1580 0.660864.0 -1 BaseEP: DELETE CMEndpoint f47a2d98 TOTAL NOW=2 CALL_LIST=1 16:31:58 2662945173mS RES: Mon 18/9/2017 16:31:58 FreeMem=47732868 Heap=45507632(1) Cache=2225236 MemObjs=33650(36418) CMMsg=8(9) ASN=0 Buff=5200 1353 999 7363 5 Links=85089(85971) BTree=3343(6936) CPU=17.07% CPUStats=18.79%/9/14/144/12024/15010/00.32%/0 /02.84% MCR=0 MCW=0 16:31:58 2662945173mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=52 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=96 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=50(TLS=5) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034 16:31:58 2662945173mS RES4: XML MemObjs=63 PoolMem=5796992(3) FreePoolMem=5781688(0) 16:31:58 2662945173mS RES5: CLog MemObjs=4866 FreePoolMem(Objs)=6968(134) TotalMem=704500 16:31:59 2662946775mS CMExtnEvt: jessenmacher: No user activity 16:31:59 2662946998mS CMExtnEvt: kstacer: Recover Timer reason=CMTRWrapUp 16:31:59 2662946998mS CMExtnEvt: v=25 State, new=Idle old=PortRecoverDelay,0,0,kstacer 16:31:59 2662946999mS CMExtnTx: v=481, p1=0 CMVoiceMailStatus Line: type=DigitalExtn 9 Call: lid=0 id=-1 in=0 Called[kstacer Msgs=0 Old=0 Sav=0] Type=Default (100) Reason=CMDRdirect Calling[00000000] Type=Default Plan=Default Display [kstacer Msgs=0] Timed: 18/09/17 16:31 16:32:10 2662957884mS CMCallEvt: 0000000000000000 0.660867.0 -1 BaseEP: NEW CMEndpoint f4832b2c TOTAL NOW=3 CALL_LIST=1 16:32:10 2662957884mS CMCallEvt: 0000000000000000 0.660867.0 -1 wmaikrzek.-1: NEW CMExtnEndpoint f4832b2c, Name=wmaikrzek, Extn=474, Phys Extn=474 16:32:10 2662957885mS CMCallEvt: CREATE CALL:180676 (f4cf64d8) 16:32:10 2662957885mS CMCallEvt: 0000000000000000 0.660868.0 -1 BaseEP: NEW CMEndpoint f16436e4 TOTAL NOW=4 CALL_LIST=1 16:32:10 2662957887mS CMExtnEvt: wmaikrzek: CMExtnHandler::SetCurrent( id: 0->660867 ) 16:32:10 2662957887mS CMExtnRx: v=474, p1=0 CMSetup Line: type=DigitalExtn 9 Call: lid=0 id=660867 in=0 Called[] Type=Default (100) Reason=CMDRdirect Calling[474] Type=Internal Plan=Default BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw IE CMIECallingPartyName (110)(Type=CMNameDefault) name=wmaikrzek IE CMIECallingPartyKName (226)(Type=CMNameDefault) name=Wendy Maikrzek 16:32:10 2662957888mS CMCallEvt: c0a8000a000a1583 0.660867.0 180676 wmaikrzek.0: StateChange: END=A CMCSIdle->CMCSDialInitiated 16:32:10 2662957888mS CMExtnEvt: v=22 State, new=Dialling old=Idle,0,0,wmaikrzek 16:32:10 2662957888mS CMTARGET: c0a8000a000a1583 0.660867.0 180676 wmaikrzek.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party= sub= calling=474 calling_sub= dir=out complete=0 ses=0 16:32:10 2662957888mS CMTARGET: c0a8000a000a1583 0.660867.0 180676 wmaikrzek.0: ADD TARGET (N): number= type=100 depth=1 nobar=1 setorig=1 ses=0 16:32:10 2662957889mS CMCallEvt: c0a8000a000a1583 0.660867.0 180676 wmaikrzek.0: StateChange: END=A CMCSDialInitiated->CMCSDialling 16:32:10 2662957890mS CMExtnTx: v=474, p1=0 CMSetupAck Line: type=DigitalExtn 9 Call: lid=0 id=660867 in=0 BChan: slot=11 chan=24 Timed: 18/09/17 16:32 16:32:10 2662957891mS CD: CALL: 0.660867.0 BState=Idle Cut=1 Music=3.0 Aend="wmaikrzek(474)" (11.24) Bend="" [] (0.0) CalledNum= () CallingNum=474 (wmaikrzek) Internal=1 Time=7 AState=DialInitiated 16:32:10 2662957893mS CMMap: a=11.24 b=0.0 D1 16:32:11 2662958194mS RES: Mon 18/9/2017 16:32:11 FreeMem=47705984 Heap=45507632(1) Cache=2198352 MemObjs=33675(36418) CMMsg=8(9) ASN=0 Buff=5200 1353 1000 7363 5 Links=85094(85971) BTree=3346(6936) CPU=17.48% CPUStats=18.59%/9/14/144/12235/15010/00.17%/ 1/02.80% MCR=0 MCW=0 16:32:11 2662958194mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=52 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=96 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=50(TLS=5) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034 16:32:11 2662958194mS RES4: XML MemObjs=63 PoolMem=5796992(3) FreePoolMem=5781688(0) 16:32:11 2662958195mS RES5: CLog MemObjs=4866 FreePoolMem(Objs)=6968(134) TotalMem=704500 16:32:11 2662958224mS CMCallEvt: 0000000000000000 0.660869.0 -1 BaseEP: NEW CMEndpoint f48291a8 TOTAL NOW=5 CALL_LIST=2 16:32:11 2662958224mS CMCallEvt: 0000000000000000 0.660869.0 -1 Book Floor 2B.-1: NEW CMExtnEndpoint f48291a8, Name=Book Floor 2B, Extn=223, Phys Extn=223 16:32:11 2662958224mS CMCallEvt: CREATE CALL:180677 (f16b82e8) 16:32:11 2662958224mS CMCallEvt: 0000000000000000 0.660870.0 -1 BaseEP: NEW CMEndpoint f171e7e8 TOTAL NOW=6 CALL_LIST=2 16:32:11 2662958227mS CMExtnEvt: Book Floor 2B: CMExtnHandler::SetCurrent( id: 0->660869 ) 16:32:11 2662958227mS CMExtnRx: v=223, p1=0 CMSetup Line: type=DigitalExtn 6 Call: lid=0 id=660869 in=0 Called[] Type=Default (100) Reason=CMDRdirect Calling[223] Type=Internal Plan=Default BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw IE CMIECallingPartyName (110)(Type=CMNameDefault) name=Book Floor 2B IE CMIECallingPartyKName (226)(Type=CMNameDefault) name=Booking Floor 2B 16:32:11 2662958227mS CMCallEvt: c0a8000a000a1585 0.660869.0 180677 Book Floor 2B.0: StateChange: END=A CMCSIdle->CMCSDialInitiated 16:32:11 2662958227mS CMExtnEvt: v=10 State, new=Dialling old=Idle,0,0,Book Floor 2B 16:32:11 2662958228mS CMTARGET: c0a8000a000a1585 0.660869.0 180677 Book Floor 2B.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party= sub= calling=223 calling_sub= dir=out complete=0 ses=0 16:32:11 2662958228mS CMTARGET: c0a8000a000a1585 0.660869.0 180677 Book Floor 2B.0: ADD TARGET (N): number= type=100 depth=1 nobar=1 setorig=1 ses=0 16:32:11 2662958229mS CMCallEvt: c0a8000a000a1585 0.660869.0 180677 Book Floor 2B.0: StateChange: END=A CMCSDialInitiated->CMCSDialling 16:32:11 2662958229mS CMExtnTx: v=223, p1=0 CMSetupAck Line: type=DigitalExtn 6 Call: lid=0 id=660869 in=0 BChan: slot=8 chan=12 Timed: 18/09/17 16:32 16:32:11 2662958231mS CD: CALL: 0.660869.0 BState=Idle Cut=1 Music=3.0 Aend="Book Floor 2B(223)" (8.12) Bend="" [] (0.0) CalledNum= () CallingNum=223 (Book Floor 2B) Internal=1 Time=7 AState=DialInitiated 16:32:11 2662958232mS CMMap: a=8.12 b=0.0 D1 16:32:12 2662959710mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,474: Menu Key Pressed 4:A 16:32:14 2662961226mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,474: Menu Key Pressed 4:A 16:32:14 2662961226mS CMExtnRx: v=474, p1=0 CMInformation Line: type=DigitalExtn 9 Call: lid=0 id=660867 in=0 Called[519895506799] Type=Default (100) Reason=CMDRdirect SndComp 16:32:14 2662961227mS CMTARGET: c0a8000a000a1583 0.660867.0 180676 wmaikrzek.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=519895506799 sub= calling=474 calling_sub= dir=out complete=1 ses=0 16:32:14 2662961227mS CMTARGET: c0a8000a000a1583 0.660867.0 180676 wmaikrzek.0: ADD TARGET (N): number=519895506799 type=100 depth=1 nobar=1 setorig=1 ses=0 16:32:14 2662961228mS CMTARGET: c0a8000a000a1583 0.660867.0 180676 wmaikrzek.0: USER SC: 519895506799 3 19895506799 sc=type=Dial code=5N;, num=NSi9892696497 16:32:14 2662961228mS CMARS: FindActiveARSByGroupID GroupID=0 - Not Found 16:32:14 2662961228mS CMLRQ: FindActiveLRQByGroupID GroupID=0 - Not Found 16:32:14 2662961229mS CMCallEvt: 0000000000000000 0.660871.0 -1 BaseEP: NEW CMEndpoint f47a2d98 TOTAL NOW=7 CALL_LIST=3 16:32:14 2662961229mS CMTARGET: ISDN BChannel 23: in-service check = 1 16:32:14 2662961229mS CMTARGET: ISDN BChannel 23: in-service check = 1 16:32:14 2662961231mS CMTARGET: DIAL LINE: 180676 GROUP = 0 SUCCESS = f47a2d98 16:32:14 2662961231mS CMTARGET: c0a8000a000a1583 0.660867.0 180676 wmaikrzek.0: CancelTimer CMTCDialToneTimeout 16:32:14 2662961231mS CMTARGET: c0a8000a000a1583 0.660867.0 180676 wmaikrzek.0: INITIAL TARGETING SUCCEEDED 16:32:14 2662961231mS CMTARGET: c0a8000a000a1583 0.660867.0 180676 wmaikrzek.0: GetNoAnswerTimer:15 16:32:14 2662961232mS CMCallEvt: c0a8000a000a1583 0.660867.0 180676 wmaikrzek.0: StateChange: END=A CMCSDialling->CMCSDialled 16:32:14 2662961232mS CMExtnEvt: v=22 State, new=Proceeding old=Dialling,0,0,wmaikrzek 16:32:14 2662961233mS CMExtnTx: v=474, p1=0 CMProceeding Line: type=DigitalExtn 9 Call: lid=0 id=660867 in=0 Timed: 18/09/17 16:32 16:32:14 2662961233mS CMCallEvt: 0000000000000000 0.660868.0 180676 TargetingEP: StateChange: END=B CMCSIdle->CMCSOffering 16:32:14 2662961234mS CMCallEvt: c0a8000a000a1587 0.660871.0 180676 Q931 Trunk:5 CHAN=23: StateChange: END=T CMCSIdle->CMCSOffering 16:32:14 2662961234mS PRN: Setting configured voice gain for ch 23. 16:32:14 2662961234mS CMLineTx: v=5 CMSetup Line: type=Q931Line 5 Call: lid=0 id=660871 in=0 Called[19895506799] Type=National (2) Reason=CMDRdirect Calling[9892696497] Type=National Plan=ISDN BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw BChan: slot=0 chan=23 Timed: 18/09/17 16:32 Locale: enu 16:32:14 2662961235mS CD: CALL: 0.660867.0 BState=Idle Cut=1 Music=0.0 Aend="wmaikrzek(474)" (11.24) Bend="Line 5" [Line 5] (0.0) CalledNum=519895506799 () CallingNum=474 (wmaikrzek) Internal=0 Time=3351 AState=Dialled 16:32:14 2662961236mS ISDNL3Evt: v=5 stacknum=5 State, new=Initiated, old=NullState id=660871 16:32:14 2662961238mS CMMap: a=11.24 b=0.0 D0 16:32:14 2662961259mS ISDNL3Evt: v=5 stacknum=5 State, new=Proceeding, old=Initiated id=660871 16:32:14 2662961259mS CMLineRx: v=5 CMProceeding Line: type=Q931Line 5 Call: lid=0 id=660871 in=0 BChan: slot=0 chan=23 16:32:14 2662961260mS CMCallEvt: 0000000000000000 0.660868.0 180676 TargetingEP: RequestEnd c0a8000a000a1587 0.660871.0 180676 Q931 Trunk:5 CHAN=23 16:32:14 2662961260mS CMTARGET: c0a8000a000a1583 0.660867.0 180676 wmaikrzek.0: CancelTimer CMTCNoAnswerTimeout 16:32:14 2662961260mS CMCallEvt: 0000000000000000 0.660868.0 -1 BaseEP: DELETE CMEndpoint f16436e4 TOTAL NOW=6 CALL_LIST=3 16:32:14 2662961260mS CMCallEvt: c0a8000a000a1587 0.660871.0 180676 Q931 Trunk:5 CHAN=23: StateChange: END=B CMCSOffering->CMCSAccept 16:32:14 2662961261mS CD: CALL: 0.660867.0 BState=Ringing Cut=3 Music=0.0 Aend="wmaikrzek(474)" (11.24) Bend="Line 5" [Line 5] (3.24) CalledNum=19895506799 () CallingNum=474 (wmaikrzek) Internal=0 Time=3377 AState=Dialled 16:32:14 2662961263mS CMMap: PCG::MapBChan pcp[236]b1r0 cp_b f497c9f8 other_cp_b 0 type CGTypeSimple 16:32:14 2662961263mS CMMap: PCG::MapBChan pcp[94]b1r0 cp_b f534dbc8 other_cp_b f497c9f8 type CGTypeSimple 16:32:14 2662961263mS CMMap: a=11.24 b=3.24 M12 16:32:15 2662962221mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,223: Digit Key Pressed 3 16:32:15 2662962222mS CMExtnRx: v=223, p1=0 CMInformation Line: type=DigitalExtn 6 Call: lid=0 id=660869 in=0 Called[3] Type=Default (100) Reason=CMDRdirect Keypad[3] 16:32:15 2662962222mS CMTARGET: c0a8000a000a1585 0.660869.0 180677 Book Floor 2B.0: Setting Hard Timer 4000 16:32:15 2662962222mS CMTARGET: c0a8000a000a1585 0.660869.0 180677 Book Floor 2B.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=3 sub= calling=223 calling_sub= dir=out complete=0 ses=0 16:32:15 2662962222mS CMTARGET: c0a8000a000a1585 0.660869.0 180677 Book Floor 2B.0: ADD TARGET (N): number=3 type=100 depth=1 nobar=1 setorig=1 ses=0 16:32:15 2662962224mS CMMap: a=8.12 b=0.0 D0 16:32:15 2662962696mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,223: Digit Key Pressed 7 16:32:15 2662962697mS CMExtnRx: v=223, p1=0 CMInformation Line: type=DigitalExtn 6 Call: lid=0 id=660869 in=0 Called[7] Type=Default (100) Reason=CMDRdirect Keypad[7] 16:32:15 2662962697mS CMTARGET: c0a8000a000a1585 0.660869.0 180677 Book Floor 2B.0: Setting Hard Timer 4000 16:32:15 2662962697mS CMTARGET: c0a8000a000a1585 0.660869.0 180677 Book Floor 2B.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=37 sub= calling=223 calling_sub= dir=out complete=0 ses=0 16:32:15 2662962697mS CMTARGET: c0a8000a000a1585 0.660869.0 180677 Book Floor 2B.0: ADD TARGET (N): number=37 type=100 depth=1 nobar=1 setorig=1 ses=0 16:32:16 2662963186mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,223: Digit Key Pressed 4 16:32:16 2662963187mS CMExtnRx: v=223, p1=0 CMInformation Line: type=DigitalExtn 6 Call: lid=0 id=660869 in=0 Called[4] Type=Default (100) Reason=CMDRdirect Keypad[4] 16:32:16 2662963187mS CMTARGET: c0a8000a000a1585 0.660869.0 180677 Book Floor 2B.0: Setting Hard Timer 4000 16:32:16 2662963187mS CMTARGET: c0a8000a000a1585 0.660869.0 180677 Book Floor 2B.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=374 sub= calling=223 calling_sub= dir=out complete=0 ses=0 16:32:16 2662963187mS CMTARGET: c0a8000a000a1585 0.660869.0 180677 Book Floor 2B.0: ADD TARGET (N): number=374 type=100 depth=1 nobar=1 setorig=1 ses=0 16:32:16 2662963187mS CMTARGET: c0a8000a000a1585 0.660869.0 180677 Book Floor 2B.0: SET USER: tpiotter orig=1 16:32:16 2662963188mS CMTARGET: c0a8000a000a1585 0.660869.0 180677 Book Floor 2B.0: ADD USER: tpiotter depth=1 disallow_cw=0 dnd=0 real_call=1 group_call=0 type(CMNTypeDefault) incl(0x0) excpt(0x0), allow_redir(1) remote=00000000 simult 0 (0) 16:32:16 2662963188mS CMCallEvt: 0000000000000000 0.660872.0 -1 BaseEP: NEW CMEndpoint f487b9e4 TOTAL NOW=7 CALL_LIST=3 16:32:16 2662963188mS CMCallEvt: 0000000000000000 0.660872.0 -1 tpiotter.-1: NEW CMExtnEndpoint f487b9e4, Name=tpiotter, Extn=374, Phys Extn=374 16:32:16 2662963189mS CMTARGET: c0a8000a000a1588 0.660872.0 180677 tpiotter.0: ADD PRIMARY 16:32:16 2662963190mS CMTARGET: c0a8000a000a1585 0.660869.0 180677 Book Floor 2B.0: CancelTimer CMTCDelayedProcessing 16:32:16 2662963190mS CMTARGET: c0a8000a000a1585 0.660869.0 180677 Book Floor 2B.0: INITIAL TARGETING SUCCEEDED 16:32:16 2662963190mS CMTARGET: c0a8000a000a1585 0.660869.0 180677 Book Floor 2B.0: GetNoAnswerTimer:15 16:32:16 2662963190mS CMCallEvt: 0000000000000000 0.660870.0 180677 TargetingEP: StateChange: END=B CMCSIdle->CMCSOffering 16:32:16 2662963191mS CMCallEvt: c0a8000a000a1588 0.660872.0 180677 tpiotter.0: StateChange: END=T CMCSIdle->CMCSOffering 16:32:16 2662963192mS CMExtnEvt: tpiotter: CMExtnHandler::SetCurrent( id: 0->660872 ) 16:32:16 2662963192mS CMExtnTx: v=374, p1=0 CMSetup Line: type=DigitalExtn 8 Call: lid=0 id=660872 in=0 Called[374] Type=Default (100) Reason=CMDRdirect Calling[223] Type=Internal Plan=Default BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw IE CMIECallingPartyName (110)(Type=CMNameDefault) name=Book Floor 2B IE CMIECalledPartyName (224)(Type=CMNameDefault) name=tpiotter IE CMIECalledPartyKName (225)(Type=CMNameDefault) name=Tamara Piotter IE CMIECallingPartyKName (226)(Type=CMNameDefault) name=Booking Floor 2B IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=Book Floor 2B IE CMIERespondingPartyKName (229)(Type=CMNameDefault) name=Booking Floor 2B IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=223 IE CMIEDeviceDetail (231) c0a8000a000a1585 LOCALE=enu HW=15 VER=9 class=CMDeviceStdPhone type=109 number=110 channel=0 features=0x10000420 rx_gain=32 tx_gain=32 ep_callid=660869 ipaddr=192.168.0.10 apps=0 loc=0 em_loc=1 features2=0x0 is_spcall =0 IE CMIEMohSourceId (247) MOH Source = 255 Display [Book Floor 2B>tpiotter] Timed: 18/09/17 16:32 Locale: enu 16:32:16 2662963192mS CMExtnRx: v=374, p1=0 CMAlerting Line: type=DigitalExtn 8 Call: lid=0 id=660872 in=0 16:32:16 2662963192mS CMCallEvt: c0a8000a000a1588 0.660872.0 180677 tpiotter.0: StateChange: END=T CMCSOffering->CMCSRinging 16:32:16 2662963193mS CMExtnEvt: v=19 State, new=Ringing old=Idle,0,0,tpiotter 16:32:16 2662963194mS CMCallEvt: 0000000000000000 0.660870.0 180677 TargetingEP: StateChange: END=B CMCSOffering->CMCSRinging 16:32:16 2662963194mS CMCallEvt: c0a8000a000a1585 0.660869.0 180677 Book Floor 2B.0: StateChange: END=A CMCSDialling->CMCSRingBack 16:32:16 2662963195mS CMExtnEvt: v=10 State, new=Alerting old=Dialling,0,0,Book Floor 2B 16:32:16 2662963195mS CMExtnTx: v=223, p1=0 CMAlerting Line: type=DigitalExtn 6 Call: lid=0 id=660869 in=0 IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=tpiotter IE CMIERespondingPartyKName (229)(Type=CMNameDefault) name=Tamara Piotter IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=374 IE CMIEDeviceDetail (231) c0a8000a000a1588 LOCALE=enu HW=15 VER=9 class=CMDeviceStdPhone type=109 number=319 channel=0 features=0x10000400 rx_gain=32 tx_gain=32 ep_callid=660872 ipaddr=192.168.0.10 apps=0 loc=0 em_loc=1 features2=0x0 is_spcall =0 Timed: 18/09/17 16:32 16:32:16 2662963196mS CD: CALL: 0.660869.0 BState=Ringing Cut=1 Music=2.0 Aend="Book Floor 2B(223)" (8.12) Bend="tpiotter(374)" [tpiotter(374)] (0.0) CalledNum=374 (tpiotter) CallingNum=223 (Book Floor 2B) Internal=1 Time=4972 AState=Ringing 16:32:16 2662963198mS CMMap: a=8.12 b=0.0 R1 16:32:16 2662963200mS RES: Mon 18/9/2017 16:32:16 FreeMem=47667072 Heap=45507632(1) Cache=2159440 MemObjs=33725(36418) CMMsg=8(9) ASN=0 Buff=5200 1349 996 7363 5 Links=85069(85971) BTree=3351(6936) CPU=17.67% CPUStats=18.79%/11/8/144/12009/15010/00.15%/1 /02.81% MCR=0 MCW=0 16:32:16 2662963200mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=52 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=122 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=50(TLS=5) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034 16:32:16 2662963200mS RES4: XML MemObjs=63 PoolMem=5796992(3) FreePoolMem=5781688(0) 16:32:16 2662963200mS RES5: CLog MemObjs=4866 FreePoolMem(Objs)=6968(134) TotalMem=704500 16:32:16 2662963888mS CMLineRx: v=5 CMProgress Line: type=Q931Line 5 Call: lid=0 id=660871 in=0 IE CMIEProgressIndicator (30) cs=CMCSITUT (0), loc=CMLPrivateNetLocalUser (1), pd=CMPDInbandPattern (8) 16:32:16 2662963889mS CMCallEvt: c0a8000a000a1587 0.660871.0 180676 Q931 Trunk:5 CHAN=23: StateChange: END=B CMCSAccept->CMCSRinging 16:32:16 2662963889mS CMCallEvt: c0a8000a000a1583 0.660867.0 180676 wmaikrzek.0: StateChange: END=A CMCSDialled->CMCSRingBack 16:32:16 2662963890mS CMExtnEvt: v=22 State, new=Alerting old=Proceeding,0,0,wmaikrzek 16:32:16 2662963890mS CMExtnTx: v=474, p1=0 CMProgress Line: type=DigitalExtn 9 Call: lid=0 id=660867 in=0 IE CMIEProgressIndicator (30) cs=CMCSITUT (0), loc=CMLPrivateNetLocalUser (1), pd=CMPDInbandPattern (8) IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=519895506799 IE CMIEDeviceDetail (231) c0a8000a000a1587 LOCALE=enu HW=15 VER=9 class=CMDeviceISDNTrunk type=2 number=5 channel=23 features=0x0 rx_gain=32 tx_gain=32 ep_callid=660871 ipaddr=192.168.0.10 apps=0 loc=0 em_loc=0 features2=0x0 is_spcall=1 Timed: 18/09/17 16:32 16:32:16 2662963891mS CD: CALL: 0.660867.0 BState=Ringing Cut=3 Music=0.0 Aend="wmaikrzek(474)" (11.24) Bend="Line 5" [Line 5] (3.24) CalledNum=19895506799 () CallingNum=474 (wmaikrzek) Internal=0 Time=6007 AState=Ringing 16:32:23 2662970311mS ISDNL3Evt: v=5 stacknum=5 State, new=Active, old=Proceeding id=660871 16:32:23 2662970312mS CMLineRx: v=5 CMConnect Line: type=Q931Line 5 Call: lid=0 id=660871 in=0 IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:0 R:4) number=51?19895506799 16:32:23 2662970312mS CMCallEvt: c0a8000a000a1587 0.660871.0 180676 Q931 Trunk:5 CHAN=23: StateChange: END=B CMCSRinging->CMCSConnReq 16:32:23 2662970312mS CMCallEvt: c0a8000a000a1583 0.660867.0 180676 wmaikrzek.0: StateChange: END=A CMCSRingBack->CMCSOGConnReq 16:32:23 2662970312mS CMExtnEvt: v=22 State, new=Connected old=Alerting,0,0,wmaikrzek 16:32:23 2662970313mS CMExtnTx: v=474, p1=0 CMConnect Line: type=DigitalExtn 9 Call: lid=0 id=660867 in=0 IE CMIERespondingPartyNumber (230)(P:100 S:100 T:0 N:100 R:4) number=519895506799 IE CMIEDeviceDetail (231) c0a8000a000a1587 LOCALE=enu HW=15 VER=9 class=CMDeviceISDNTrunk type=2 number=5 channel=23 features=0x0 rx_gain=32 tx_gain=32 ep_callid=660871 ipaddr=192.168.0.10 apps=0 loc=0 em_loc=0 features2=0x0 is_spcall=1 Timed: 18/09/17 16:32 16:32:23 2662970313mS CMExtnRx: v=474, p1=0 CMConnectAck Line: type=DigitalExtn 9 Call: lid=0 id=660867 in=0 16:32:23 2662970313mS CMCallEvt: c0a8000a000a1583 0.660867.0 180676 wmaikrzek.0: StateChange: END=A CMCSOGConnReq->CMCSConnected 16:32:23 2662970313mS CMTARGET: c0a8000a000a1583 0.660867.0 180676 wmaikrzek.0: ~CMTargetHandler f1749e0c ep f4832b2c 16:32:23 2662970315mS CMCallEvt: c0a8000a000a1587 0.660871.0 180676 Q931 Trunk:5 CHAN=23: StateChange: END=B CMCSConnReq->CMCSConnected 16:32:23 2662970315mS CMLineTx: v=5 CMConnectAck Line: type=Q931Line 5 Call: lid=0 id=660871 in=0 BChan: slot=0 chan=23 16:32:23 2662970316mS CD: CALL: 0.660867.0 BState=Connected Cut=3 Music=0.0 Aend="wmaikrzek(474)" (11.24) Bend="Line 5" [Line 5] (3.24) CalledNum=19895506799 () CallingNum=474 (wmaikrzek) Internal=0 Time=12432 AState=Connected 16:32:23 2662970704mS RES: Mon 18/9/2017 16:32:24 FreeMem=47672680 Heap=45507632(1) Cache=2165048 MemObjs=33741(36418) CMMsg=8(9) ASN=0 Buff=5200 1353 1000 7364 5 Links=85109(85971) BTree=3351(6936) CPU=17.60% CPUStats=17.13%/1/4/144/12353/15010/00.13%/0 /02.76% MCR=0 MCW=0 16:32:23 2662970704mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=52 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=97 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=50(TLS=5) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034 16:32:23 2662970704mS RES4: XML MemObjs=63 PoolMem=5796992(3) FreePoolMem=5781688(0) 16:32:23 2662970705mS RES5: CLog MemObjs=4866 FreePoolMem(Objs)=6968(134) TotalMem=704500 16:32:25 2662972486mS H323Evt: Recv: RegistrationRequest 192.168.1.103; Extn(251), time since last RRQ-KA 55011, Endpoints registered: 13; Endpoints in registration: 0 16:32:26 2662973190mS CMTARGET: c0a8000a000a1585 0.660869.0 180677 Book Floor 2B.0: TimerExpired cause=CMTCCoverageTimeout 16:32:26 2662973190mS CMTARGET: c0a8000a000a1585 0.660869.0 180677 Book Floor 2B.0: GetNoAnswerTimer:15 16:32:27 2662974589mS CMExtnRx: v=223, p1=0 CMReleaseComp Line: type=DigitalExtn 6 Call: lid=0 id=660869 in=0 16:32:27 2662974590mS CMCallEvt: c0a8000a000a1585 0.660869.0 180677 Book Floor 2B.0: StateChange: END=A CMCSRingBack->CMCSCompleted 16:32:27 2662974590mS CMTARGET: c0a8000a000a1585 0.660869.0 180677 Book Floor 2B.0: CancelTimer CMTCNoAnswerTimeout 16:32:27 2662974590mS CMExtnEvt: v=10 State, new=PortRecoverDelay old=Alerting,0,0,Book Floor 2B 16:32:27 2662974592mS CMLOGGING: CALL:2017/09/1816:32,00:00:00,011,223,O,374,374,BookFloor2B,,,1,,"",0,n/a 16:32:27 2662974592mS CD: CALL: 0.660869.0 BState=Ringing Cut=0 Music=0.0 Aend="Book Floor 2B(223)" (8.12) Bend="tpiotter(374)" [tpiotter(374)] (0.0) CalledNum=374 (tpiotter) CallingNum=223 (Book Floor 2B) Internal=1 Time=16368 AState=Idle 16:32:27 2662974592mS CD: CALL: 0.660869.0 Deleted 16:32:27 2662974593mS CMExtnEvt: Book Floor 2B: CALL LOST (CMCauseNormal) 16:32:27 2662974593mS CMExtnEvt: Book Floor 2B: Extn(223) Calling Party Number(223) Type(CMNTypeInternal) 16:32:27 2662974593mS CMExtnEvt: Book Floor 2B: CMExtnHandler::SetCurrent( id: 660869->0 ) 16:32:27 2662974593mS CMCallEvt: c0a8000a000a1585 0.660869.0 -1 Book Floor 2B.-1: StateChange: END=X CMCSCompleted->CMCSDelete 16:32:27 2662974594mS CMCallEvt: 0000000000000000 0.660870.0 -1 BaseEP: DELETE CMEndpoint f171e7e8 TOTAL NOW=6 CALL_LIST=2 16:32:27 2662974594mS CMExtnEvt: tpiotter: CALL LOST (CMCauseNormal) 16:32:27 2662974594mS CMExtnEvt: tpiotter: Extn(374) Calling Party Number(223) Type(CMNTypeInternal) 16:32:27 2662974595mS CMCallEvt: c0a8000a000a1588 0.660872.0 -1 tpiotter.0: StateChange: END=X CMCSRinging->CMCSCompleted 16:32:27 2662974595mS CMExtnEvt: v=19 State, new=PortRecoverDelay old=Ringing,0,0,tpiotter 16:32:27 2662974597mS CMExtnTx: v=374, p1=0 CMReleaseComp Line: type=DigitalExtn 8 Call: lid=0 id=660872 in=0 Called[374] Type=Default (100) Reason=CMDRdirect Calling[223] Type=Internal Plan=Default Cause=16, Normal call clearing Timed: 18/09/17 16:32 16:32:27 2662974597mS CMExtnEvt: tpiotter: CMExtnHandler::SetCurrent( id: 660872->0 ) 16:32:27 2662974597mS CMCallEvt: c0a8000a000a1588 0.660872.0 -1 tpiotter.-1: StateChange: END=X CMCSCompleted->CMCSDelete 16:32:27 2662974598mS CMCallEvt: c0a8000a000a1588 0.660872.0 -1 BaseEP: DELETE CMEndpoint f487b9e4 TOTAL NOW=5 CALL_LIST=2 16:32:27 2662974598mS CMCallEvt: END CALL:180677 (f16b82e8) 16:32:27 2662974599mS CMTARGET: c0a8000a000a1585 0.660869.0 -1 BaseEP: ~CMTargetHandler f1717bbc ep f48291a8 16:32:27 2662974599mS CMCallEvt: c0a8000a000a1585 0.660869.0 -1 BaseEP: DELETE CMEndpoint f48291a8 TOTAL NOW=4 CALL_LIST=2 16:32:27 2662974602mS CMMap: a=8.12 b=0.0 R0 16:32:27 2662974603mS PRN: Config Write Wake Up 16:32:27 2662974608mS CMExtnEvt: tpiotter: Recover Timer reason=CMTRWrapUp 16:32:27 2662974608mS CMExtnEvt: v=19 State, new=Idle old=PortRecoverDelay,0,0,tpiotter 16:32:27 2662974815mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,471: Menu Key Pressed 9:F 16:32:28 2662975103mS PRN: Updates IO list size 1 updated list size 1 16:32:28 2662975103mS PRN: Sending Updates out to f497c45c started 16:32:28 2662975103mS PRN: Sending Updates out to f497c45c finished 16:32:28 2662975104mS PRN: Config Write Completed 16:32:30 2662976593mS CMExtnEvt: Book Floor 2B: Recover Timer reason=CMTRWrapUp 16:32:30 2662976593mS CMExtnEvt: v=10 State, new=Idle old=PortRecoverDelay,0,0,Book Floor 2B 16:32:30 2662976593mS CMExtnTx: v=223, p1=0 CMVoiceMailStatus Line: type=DigitalExtn 6 Call: lid=0 id=-1 in=0 Called[Book Floor 2B Msgs=0 Old=0 Sav=1] Type=Default (100) Reason=CMDRdirect Calling[00000000] Type=Default Plan=Default Display [Book Floor 2B Msgs=0] Timed: 18/09/17 16:32 16:32:31 2662977803mS H323Evt: Recv: RegistrationRequest 192.168.1.106; Extn(254), time since last RRQ-KA 55012, Endpoints registered: 13; Endpoints in registration: 0 16:32:34 2662980734mS H323Evt: Recv: RegistrationRequest 192.168.1.105; Extn(253), time since last RRQ-KA 55011, Endpoints registered: 13; Endpoints in registration: 0 ********** SysMonitor v9.1.6.0 build 153 [connected to 192.168.0.10 (Huron County)] ********** 16:32:36 2662982606mS PRN: Monitor Status IP 500 V2 9.1.6.0 build 153 16:32:36 2662982606mS PRN: LAW=U PRI=2, BRI=0, ALOG=4, VCOMP=10, MDM=0, WAN=0, MODU=5 LANM=0 CkSRC=5 VMAIL=1(VER=3 TYP=1) 1-X=0 CALLS=2(TOT=180677) 16:32:42 2662988475mS H323Evt: Recv: RegistrationRequest 192.168.252.132; Extn(601), time since last RRQ-KA 55044, Endpoints registered: 13; Endpoints in registration: 0 16:32:42 2662988566mS H323Evt: Recv: RegistrationRequest 192.168.252.139; Extn(612), time since last RRQ-KA 55046, Endpoints registered: 13; Endpoints in registration: 0 16:32:42 2662988618mS SIP Rx: UDP 192.168.1.108:5060 -> 10.1.0.21:5060 OPTIONS sip:9892693555@192.168.1.108 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.108:5060;branch=z9hG4bKac1426997404 Max-Forwards: 70 From: ;tag=1c1426960887 To: Call-ID: 1426956963199201723250@192.168.1.108 CSeq: 1 OPTIONS Contact: Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE User-Agent: MP-124E FXS/v.6.60A.332.002 Accept: application/sdp, application/simple-message-summary, message/sipfrag Content-Length: 0 16:32:42 2662988623mS SIP Tx: UDP 10.1.0.21:5060 -> 192.168.1.108:5060 SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.1.108:5060;branch=z9hG4bKac1426997404 From: ;tag=1c1426960887 Call-ID: 1426956963199201723250@192.168.1.108 CSeq: 1 OPTIONS Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,INFO,REFER,NOTIFY,UPDATE Supported: timer Server: IP Office 9.1.6.0 build 153 To: ;tag=a6a3fe159ae403dc Content-Type: application/sdp Content-Length: 233 v=0 o=UserA 4066831242 1421749226 IN IP4 0.0.0.0 s=Session SDP c=IN IP4 0.0.0.0 t=0 0 m=audio 8000 RTP/AVP 0 8 18 4 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:4 G723/16000 16:32:42 2662988745mS RES: Mon 18/9/2017 16:32:42 FreeMem=47663660 Heap=45474844(1) Cache=2188816 MemObjs=33830(36418) CMMsg=8(9) ASN=0 Buff=5200 1353 1000 7363 5 Links=85106(85971) BTree=3349(6936) CPU=18.43% CPUStats=17.42%/1/5/144/12293/15010/00.14%/1 /02.79% MCR=0 MCW=0 16:32:42 2662988745mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=52 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=97 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=50(TLS=5) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034 16:32:42 2662988745mS RES4: XML MemObjs=63 PoolMem=5796992(3) FreePoolMem=5781688(0) 16:32:42 2662988745mS RES5: CLog MemObjs=4866 FreePoolMem(Objs)=6968(134) TotalMem=704500 16:32:43 2662989017mS H323Evt: Recv: RegistrationRequest 192.168.252.136; Extn(606), time since last RRQ-KA 55045, Endpoints registered: 13; Endpoints in registration: 0 16:32:43 2662989940mS H323Evt: Recv: RegistrationRequest 192.168.1.104; Extn(252), time since last RRQ-KA 55011, Endpoints registered: 13; Endpoints in registration: 0 16:32:43 2662989953mS H323Evt: Recv: RegistrationRequest 192.168.252.134; Extn(604), time since last RRQ-KA 55053, Endpoints registered: 13; Endpoints in registration: 0 16:32:45 2662991872mS H323Evt: Recv: RegistrationRequest 192.168.252.138; Extn(611), time since last RRQ-KA 55043, Endpoints registered: 13; Endpoints in registration: 0 16:32:47 2662993748mS RES: Mon 18/9/2017 16:32:47 FreeMem=47708896 Heap=45507632(1) Cache=2201264 MemObjs=33694(36418) CMMsg=8(9) ASN=0 Buff=5200 1353 1000 7363 5 Links=85102(85971) BTree=3349(6936) CPU=18.29% CPUStats=18.01%/1/4/144/12248/15010/00.12%/1 /02.78% MCR=0 MCW=0 16:32:47 2662993748mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=52 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=96 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=50(TLS=5) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034 16:32:47 2662993748mS RES4: XML MemObjs=63 PoolMem=5796992(3) FreePoolMem=5781688(0) 16:32:47 2662993748mS RES5: CLog MemObjs=4866 FreePoolMem(Objs)=6968(134) TotalMem=704500 16:32:49 2662995478mS H323Evt: Recv: RegistrationRequest 192.168.252.133; Extn(495), time since last RRQ-KA 55048, Endpoints registered: 13; Endpoints in registration: 0 16:32:49 2662995489mS H323Evt: Recv: RegistrationRequest 192.168.252.137; Extn(609), time since last RRQ-KA 55042, Endpoints registered: 13; Endpoints in registration: 0 16:32:49 2662995501mS H323Evt: Recv: RegistrationRequest 192.168.252.135; Extn(605), time since last RRQ-KA 55045, Endpoints registered: 13; Endpoints in registration: 0 16:32:52 2662998079mS H323Evt: Recv: RegistrationRequest 192.168.1.102; Extn(250), time since last RRQ-KA 55019, Endpoints registered: 13; Endpoints in registration: 0 16:32:53 2662999225mS PRN: Optimizing BTree Lists Completed...Started:2662999224 Duration:1 Size:382 Attempted:382 16:32:59 2663005002mS CMExtnEvt: kstacer: No user activity 16:33:12 2663018284mS PRN: Created WAV file MOH Source 1 16:33:12 2663018630mS PRN: Loading HoldMusic.wav from ipaddr=255.255.255.255 16:33:12 2663018666mS RES: Mon 18/9/2017 16:33:12 FreeMem=46988188 Heap=44787612(1) Cache=2200576 MemObjs=33698(36418) CMMsg=8(9) ASN=0 Buff=5200 1353 1000 7364 5 Links=85102(85971) BTree=3345(6936) CPU=17.18% CPUStats=17.52%/1/5/144/12248/15010/00.16%/0 /02.79% MCR=0 MCW=0 16:33:12 2663018666mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=52 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=94 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=50(TLS=5) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034 16:33:12 2663018667mS RES4: XML MemObjs=63 PoolMem=5796992(3) FreePoolMem=5781688(0) 16:33:12 2663018667mS RES5: CLog MemObjs=4866 FreePoolMem(Objs)=6968(134) TotalMem=704500 16:33:12 2663018879mS PRN: WAV Hold Music HoldMusic.wav failed to load 16:33:12 2663018879mS PRN: Deleted WAV file MOH Source 1 16:33:12 2663018879mS PRN: Created Tone MOH Source 1 16:33:12 2663018879mS PRN: Stopped tone MOH Source 1 16:33:12 2663018879mS PRN: Deleted Tone MOH Source 1 16:33:12 2663018880mS PRN: Playing tone MOH Source 1 16:33:15 2663021226mS CMExtnEvt: wmaikrzek: No user activity 16:33:21 2663027499mS H323Evt: Recv: RegistrationRequest 192.168.1.103; Extn(251), time since last RRQ-KA 55013, Endpoints registered: 13; Endpoints in registration: 0 16:33:26 2663032814mS H323Evt: Recv: RegistrationRequest 192.168.1.106; Extn(254), time since last RRQ-KA 55011, Endpoints registered: 13; Endpoints in registration: 0 16:33:28 2663034600mS CMExtnEvt: Book Floor 2B: No user activity 16:33:28 2663034825mS CMExtnEvt: dkidd: No user activity 16:33:29 2663035745mS H323Evt: Recv: RegistrationRequest 192.168.1.105; Extn(253), time since last RRQ-KA 55011, Endpoints registered: 13; Endpoints in registration: 0 16:33:36 2663042176mS CMTARGET: ISDN BChannel 1: in-service check = 1 16:33:36 2663042176mS ISDNL3Evt: v=6 stacknum=6 State, new=Present, old=NullState id=12 16:33:36 2663042177mS CMLineRx: v=6 CMSetup Line: type=Q931Line 6 Call: lid=6 id=12 in=1 Called[9892696500] Type=Unknown (0) Reason=CMDRdirect SndComp Calling[519899752158] Type=Unknown Plan=ISDN Pres=Allowed (0) BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw BChan: slot=0 chan=1 IE CMIECallingPartyName (110)(Type=CMNameDefault) name=WIRELESS CALLER Display [WIRELESS CALLER] 16:33:36 2663042177mS PRN: Q931Trunk: Found QBChannel to match 0.1 --> 3.34 16:33:36 2663042177mS CMCallEvt: 0000000000000000 0.660873.0 -1 BaseEP: NEW CMEndpoint f4818aac TOTAL NOW=5 CALL_LIST=2 16:33:36 2663042178mS CMTARGET: ISDN BChannel 1: in-service check = 1 16:33:36 2663042178mS CMTARGET: ISDN BChannel 1: in-service check = 1 16:33:36 2663042178mS CMCallEvt: CREATE CALL:180678 (f16b82e8) 16:33:36 2663042178mS CMCallEvt: 0000000000000000 0.660874.0 -1 BaseEP: NEW CMEndpoint f171e7e8 TOTAL NOW=6 CALL_LIST=2 16:33:36 2663042181mS CD: CALL: 6.12.1 BState=Idle Cut=1 Music=0.0 Aend="Line 6" (3.34) Bend="" [] (0.0) CalledNum=9892696500 () CallingNum=519899752158 (WIRELESS CALLER) Internal=0 Time=3 AState=Idle 16:33:36 2663042181mS CMCallEvt: c0a8000a0000000c 6.12.1 180678 Q931 Trunk:6 CHAN=1: StateChange: END=A CMCSIdle->CMCSDialInitiated 16:33:36 2663042181mS CMTARGET: c0a8000a0000000c 6.12.1 180678 Q931 Trunk:6 CHAN=1: LOOKUP CALL ROUTE: GID=0 type=0 called_party=9892696500 sub= calling=519899752158 calling_sub= dir=in complete=1 ses=0 16:33:36 2663042182mS CMTARGET: c0a8000a0000000c 6.12.1 180678 Q931 Trunk:6 CHAN=1: SET BESTMATCH: length 10 vs -1 match=9892696500 dest=Sheriff Records 16:33:36 2663042182mS CMCallEvt: Priority hike: call 180678 priority 0->1 16:33:36 2663042182mS CMTARGET: c0a8000a0000000c 6.12.1 180678 Q931 Trunk:6 CHAN=1: LOOKUP ICR: DDI= CGPN=519899752158 (Destination Sheriff Records ) => CDPN=Sheriff Records 16:33:36 2663042182mS CMTARGET: c0a8000a0000000c 6.12.1 180678 Q931 Trunk:6 CHAN=1: ADD TARGET (N): number=Sheriff Records type=0 depth=1 nobar=1 setorig=1 ses=0 16:33:36 2663042183mS CMTARGET: c0a8000a0000000c 6.12.1 180678 Q931 Trunk:6 CHAN=1: HG(Sheriff Records,766,192.168.0.10) Requires Routing To Master(1). IsLocalExecutive(1) 16:33:36 2663042183mS CMTARGET: c0a8000a0000000c 6.12.1 180678 Q931 Trunk:6 CHAN=1: HG call targeting occuring here 16:33:36 2663042183mS CMTARGET: c0a8000a0000000c 6.12.1 180678 Q931 Trunk:6 CHAN=1: PrimeForHGTarget: Sheriff Records setorig=1 recall=0 resetExtnVars 1 16:33:36 2663042183mS CMCallEvt: Priority hike: call 180678 priority 1->5 16:33:36 2663042183mS CMTARGET: c0a8000a0000000c 6.12.1 180678 Q931 Trunk:6 CHAN=1: AddHGTarget Sheriff Records (depth=1) allowq=1 type=CMNTypeUnknown 16:33:36 2663042183mS CMCallEvt: 0000000000000000 0.660875.0 -1 BaseEP: NEW CMEndpoint f16bdd1c TOTAL NOW=7 CALL_LIST=3 16:33:36 2663042184mS CMTARGET: FoundKnownSystemTargets ICR cache hit 16:33:36 2663042184mS CMTARGET: c0a8000a0000000c 6.12.1 180678 Q931 Trunk:6 CHAN=1: INITIAL TARGETING SUCCEEDED 16:33:36 2663042184mS CMTARGET: c0a8000a0000000c 6.12.1 180678 Q931 Trunk:6 CHAN=1: GetNoAnswerTimer:20 16:33:36 2663042184mS CMCallEvt: c0a8000a0000000c 6.12.1 180678 Q931 Trunk:6 CHAN=1: StateChange: END=A CMCSDialInitiated->CMCSDialled 16:33:36 2663042185mS CMLineTx: v=6 CMProceeding Line: type=Q931Line 6 Call: lid=6 id=12 in=1 BChan: slot=0 chan=1 16:33:36 2663042185mS CMCallEvt: 0000000000000000 0.660874.0 180678 TargetingEP: StateChange: END=B CMCSIdle->CMCSOffering 16:33:36 2663042186mS CMCallEvt: c0a8000a000a158b 0.660875.0 180678 ACDTep(Sheriff Records): StateChange: END=T CMCSIdle->CMCSOffering 16:33:36 2663042186mS CMTARGET: c0a8000a0000000c 6.12.1 180678 Q931 Trunk:6 CHAN=1: CancelTimer CMTCNoAnswerTimeout 16:33:36 2663042186mS CMCallEvt: c0a8000a000a158b 0.660875.0 180678 ACDTep(Sheriff Records): StateChange: END=T CMCSOffering->CMCSRinging 16:33:36 2663042186mS CMCallEvt: 0000000000000000 0.660874.0 180678 TargetingEP: StateChange: END=B CMCSOffering->CMCSRinging 16:33:36 2663042187mS CMCallEvt: c0a8000a0000000c 6.12.1 180678 Q931 Trunk:6 CHAN=1: StateChange: END=A CMCSDialled->CMCSRingBack 16:33:36 2663042187mS CMLineTx: v=6 CMAlerting Line: type=Q931Line 6 Call: lid=6 id=12 in=1 BChan: slot=0 chan=1 16:33:36 2663042189mS CD: CALL: 6.12.1 BState=Ringing Cut=1 Music=2.0 Aend="Line 6" (3.34) Bend="Sheriff Records(766)" [] (0.0) CalledNum=766 (Sheriff Records) CallingNum=519899752158 (WIRELESS CALLER) Internal=0 Time=11 AState=Ringing 16:33:36 2663042191mS ISDNL3Evt: v=6 stacknum=6 State, new=ICProceeding, old=Present id=12 16:33:36 2663042191mS ISDNL3Evt: v=6 stacknum=6 State, new=Received, old=ICProceeding id=12 16:33:36 2663042191mS CMMap: a=3.34 b=0.0 R1 16:33:36 2663042192mS CD: CALL: 6.12.1 BState=Ringing Cut=1 Music=2.0 Aend="Line 6" (3.34) Bend="Sheriff Records(766)" [] (0.0) CalledNum=766 (Sheriff Records) CallingNum=519899752158 (WIRELESS CALLER) Internal=0 Time=14 AState=Ringing 16:33:36 2663042193mS CMTARGET: c0a8000a0000000c 6.12.1 180678 Q931 Trunk:6 CHAN=1: PrimeForHGTarget: Sheriff Records setorig=0 recall=0 resetExtnVars 1 16:33:36 2663042193mS CMTARGET: c0a8000a0000000c 6.12.1 180678 Q931 Trunk:6 CHAN=1: AddHGTarget Sheriff Records (depth=0) allowq=0 type=CMNTypeUnknown 16:33:36 2663042193mS CMTARGET: c0a8000a0000000c 6.12.1 180678 Q931 Trunk:6 CHAN=1: AddHGTargetRingGroup Sheriff Records starting at 1 16:33:36 2663042193mS CMTARGET: c0a8000a0000000c 6.12.1 180678 Q931 Trunk:6 CHAN=1: ADD USER: kkociba depth=1 disallow_cw=0 dnd=0 real_call=1 group_call=1 type(CMNTypeUnknown) incl(0x0) excpt(0x3c), allow_redir(1) remote=00000000 simult 0 (0) 16:33:36 2663042193mS CMCallEvt: 0000000000000000 0.660876.0 -1 BaseEP: NEW CMEndpoint f48291a8 TOTAL NOW=8 CALL_LIST=3 16:33:36 2663042193mS CMCallEvt: 0000000000000000 0.660876.0 -1 kkociba.-1: NEW CMExtnEndpoint f48291a8, Name=kkociba, Extn=224, Phys Extn=224 16:33:36 2663042195mS CMTARGET: c0a8000a000a158c 0.660876.0 180678 kkociba.0: ADD PRIMARY 16:33:36 2663042195mS CMTARGET: c0a8000a0000000c 6.12.1 180678 Q931 Trunk:6 CHAN=1: Sheriff Records: Not using 220: DND 16:33:36 2663042195mS CMTARGET: c0a8000a0000000c 6.12.1 180678 Q931 Trunk:6 CHAN=1: SelectTargetAvailable 1 targets 16:33:36 2663042196mS CMCallEvt: c0a8000a000a158c 0.660876.0 180678 kkociba.0: StateChange: END=T CMCSIdle->CMCSOffering 16:33:36 2663042196mS CMExtnEvt: kkociba: CMExtnHandler::SetCurrent( id: 0->660876 ) 16:33:36 2663042196mS CMExtnTx: v=224, p1=0 CMSetup Line: type=DigitalExtn 6 Call: lid=0 id=660876 in=0 Called[224] Type=Unknown (0) Reason=CMDRdirect SndComp Calling[519899752158] Type=Unknown Plan=ISDN Pres=Allowed (0) BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw IE CMIECallingPartyName (110)(Type=CMNameDefault) name=WIRELESS CALLER IE CMIECalledPartyName (224)(Type=CMNameDefault) name=Sheriff Records IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=WIRELESS CALLER IE CMIERespondingPartyNumber (230)(P:0 S:1 T:0 N:1 R:4) number=519899752158 IE CMIEDeviceDetail (231) c0a8000a0000000c LOCALE=enu HW=15 VER=9 class=CMDeviceISDNTrunk type=2 number=6 channel=1 features=0x20 rx_gain=32 tx_gain=32 ep_callid=12 ipaddr=192.168.0.10 apps=0 loc=0 em_loc=0 features2=0x0 is_spcall=1 IE CMIERedirectingPartyName (232)(Type=CMNameDefault) name=Sheriff Records IE CMIERedirectingPartyNumber (234)(P:100 S:100 T:101 N:100 R:4) number=766 IE CMIEOriginalCalledPartyName (236)(Type=CMNameDefault) name=Sheriff Records IE CMIEOriginalCalledPartyNumber (238)(P:100 S:100 T:101 N:100 R:4) number=766 IE CMIEIcrPriorityDetail (239) Priority = 1 IE CMIEDIDNumber (245)(P:100 S:100 T:0 N:1 R:4) number=9892696500 IE CMIEMohSourceId (247) MOH Source = 1 UUI type=User2User [766..] [0x37 0x36 0x36 0xff 0xff ] Display [WIRELESS CALLER>Sheriff Records] Timed: 18/09/17 16:33 Locale: enu 16:33:36 2663042196mS CMExtnRx: v=224, p1=0 CMAlerting Line: type=DigitalExtn 6 Call: lid=0 id=660876 in=0 16:33:36 2663042197mS CMCallEvt: c0a8000a000a158c 0.660876.0 180678 kkociba.0: StateChange: END=T CMCSOffering->CMCSRinging 16:33:36 2663042197mS CMExtnEvt: v=11 State, new=Ringing old=Idle,0,0,kkociba 16:33:36 2663042198mS CMTARGET: c0a8000a0000000c 6.12.1 180678 Q931 Trunk:6 CHAN=1: GetNoAnswerTimer:20 16:33:36 2663042200mS CD: CALL: 6.12.1 BState=Ringing Cut=1 Music=2.0 Aend="Line 6" (3.34) Bend="Sheriff Records(766)" [kkociba(224)] (0.0) CalledNum=766 (Sheriff Records) CallingNum=519899752158 (WIRELESS CALLER) Internal=0 Time=22 AState=Ringing 16:33:36 2663042206mS RES: Mon 18/9/2017 16:33:35 FreeMem=47660392 Heap=45507632(1) Cache=2152760 MemObjs=33745(36418) CMMsg=8(9) ASN=0 Buff=5200 1356 996 7364 5 Links=84998(85971) BTree=3349(6936) CPU=18.51% CPUStats=19.18%/13/31/144/11998/15010/00.26%/ 0/02.84% MCR=0 MCW=0 16:33:36 2663042206mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=52 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=104 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=50(TLS=5) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034 16:33:36 2663042206mS RES4: XML MemObjs=63 PoolMem=5796992(3) FreePoolMem=5781688(0) 16:33:36 2663042206mS RES5: CLog MemObjs=4866 FreePoolMem(Objs)=6968(134) TotalMem=704500 ********** SysMonitor v9.1.6.0 build 153 [connected to 192.168.0.10 (Huron County)] ********** 16:33:36 2663042613mS PRN: Monitor Status IP 500 V2 9.1.6.0 build 153 16:33:36 2663042613mS PRN: LAW=U PRI=2, BRI=0, ALOG=4, VCOMP=10, MDM=0, WAN=0, MODU=5 LANM=0 CkSRC=5 VMAIL=1(VER=3 TYP=1) 1-X=0 CALLS=3(TOT=180678) 16:33:37 2663043520mS H323Evt: Recv: RegistrationRequest 192.168.252.132; Extn(601), time since last RRQ-KA 55045, Endpoints registered: 13; Endpoints in registration: 0 16:33:37 2663043620mS H323Evt: Recv: RegistrationRequest 192.168.252.139; Extn(612), time since last RRQ-KA 55054, Endpoints registered: 13; Endpoints in registration: 0 16:33:38 2663044064mS H323Evt: Recv: RegistrationRequest 192.168.252.136; Extn(606), time since last RRQ-KA 55047, Endpoints registered: 13; Endpoints in registration: 0 16:33:38 2663044344mS CMExtnRx: v=224, p1=0 CMConnect Line: type=DigitalExtn 6 Call: lid=0 id=660876 in=0 16:33:38 2663044344mS CMCallEvt: c0a8000a000a158c 0.660876.0 180678 kkociba.0: StateChange: END=T CMCSRinging->CMCSConnReq 16:33:38 2663044345mS CMCallEvt: 0000000000000000 0.660874.0 180678 TargetingEP: RequestEnd c0a8000a000a158c 0.660876.0 180678 kkociba.0 16:33:38 2663044346mS CMTARGET: c0a8000a0000000c 6.12.1 180678 Q931 Trunk:6 CHAN=1: Removed HG from Callinfo 16:33:38 2663044346mS CMCallEvt: c0a8000a000a158b 0.660875.0 180678 ACDTep(Sheriff Records): StateChange: END=??? CMCSRinging->CMCSDelete 16:33:38 2663044346mS CMCallEvt: c0a8000a000a158b 0.660875.0 -1 BaseEP: DELETE CMEndpoint f16bdd1c TOTAL NOW=7 CALL_LIST=3 16:33:38 2663044346mS CMTARGET: c0a8000a0000000c 6.12.1 180678 Q931 Trunk:6 CHAN=1: CancelTimer CMTCNoAnswerTimeout 16:33:38 2663044347mS CMCallEvt: 0000000000000000 0.660874.0 -1 BaseEP: DELETE CMEndpoint f171e7e8 TOTAL NOW=6 CALL_LIST=3 16:33:38 2663044347mS CMExtnEvt: v=11 State, new=Connected old=Ringing,0,0,kkociba 16:33:38 2663044348mS CMCallEvt: c0a8000a0000000c 6.12.1 180678 Q931 Trunk:6 CHAN=1: StateChange: END=A CMCSRingBack->CMCSOGConnReq 16:33:38 2663044349mS CMLineTx: v=6 CMConnect Line: type=Q931Line 6 Call: lid=6 id=12 in=1 Called[224] Type=Internal (101) Reason=CMDRdirect BChan: slot=0 chan=1 16:33:38 2663044350mS CD: CALL: 6.12.1 BState=Connected Cut=3 Music=0.0 Aend="Line 6" (3.34) Bend="" [kkociba(224)] (8.13) CalledNum=766 (Sheriff Records) CallingNum=519899752158 (WIRELESS CALLER) Internal=0 Time=2172 AState=Connected 16:33:38 2663044352mS CMMap: a=3.34 b=0.0 R0 16:33:38 2663044352mS CMMap: PCG::MapBChan pcp[95]b1r0 cp_b f52161c4 other_cp_b 0 type CGTypeSimple 16:33:38 2663044352mS CMMap: PCG::MapBChan pcp[180]b1r0 cp_b f4a77be4 other_cp_b f52161c4 type CGTypeSimple 16:33:38 2663044352mS CMMap: a=3.34 b=8.13 M12 16:33:38 2663044353mS ISDNL3Evt: v=6 stacknum=6 State, new=ConnReq, old=Received id=12 16:33:38 2663044360mS ISDNL3Evt: v=6 stacknum=6 State, new=Active, old=ConnReq id=12 16:33:38 2663044361mS CMLineRx: v=6 CMConnectAck Line: type=Q931Line 6 Call: lid=6 id=12 in=1 16:33:38 2663044361mS CMCallEvt: c0a8000a0000000c 6.12.1 180678 Q931 Trunk:6 CHAN=1: StateChange: END=A CMCSOGConnReq->CMCSConnected 16:33:38 2663044362mS CMTARGET: c0a8000a0000000c 6.12.1 180678 Q931 Trunk:6 CHAN=1: ~CMTargetHandler f1717bbc ep f4818aac 16:33:38 2663044362mS CMCallEvt: c0a8000a000a158c 0.660876.0 180678 kkociba.0: StateChange: END=B CMCSConnReq->CMCSConnected 16:33:38 2663044364mS CMExtnTx: v=224, p1=0 CMConnectAck Line: type=DigitalExtn 6 Call: lid=0 id=660876 in=0 Called[] Type=Default (100) Reason=CMDRdirect Calling[519899752158] Type=Unknown Plan=ISDN Pres=Allowed (0) IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=WIRELESS CALLER IE CMIERespondingPartyNumber (230)(P:0 S:1 T:0 N:1 R:4) number=519899752158 IE CMIEDeviceDetail (231) c0a8000a0000000c LOCALE=enu HW=15 VER=9 class=CMDeviceISDNTrunk type=2 number=6 channel=1 features=0x20 rx_gain=32 tx_gain=32 ep_callid=12 ipaddr=192.168.0.10 apps=0 loc=0 em_loc=0 features2=0x0 is_spcall=1 Timed: 18/09/17 16:33 16:33:38 2663044959mS H323Evt: Recv: RegistrationRequest 192.168.1.104; Extn(252), time since last RRQ-KA 55019, Endpoints registered: 13; Endpoints in registration: 0 16:33:38 2663044991mS H323Evt: Recv: RegistrationRequest 192.168.252.134; Extn(604), time since last RRQ-KA 55038, Endpoints registered: 13; Endpoints in registration: 0 16:33:40 2663046916mS H323Evt: Recv: RegistrationRequest 192.168.252.138; Extn(611), time since last RRQ-KA 55044, Endpoints registered: 13; Endpoints in registration: 0 16:33:42 2663048702mS SIP Rx: UDP 192.168.1.108:5060 -> 10.1.0.21:5060 OPTIONS sip:9892693555@192.168.1.108 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.108:5060;branch=z9hG4bKac30463710 Max-Forwards: 70 From: ;tag=1c30427417 To: Call-ID: 30423497199201723350@192.168.1.108 CSeq: 1 OPTIONS Contact: Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE User-Agent: MP-124E FXS/v.6.60A.332.002 Accept: application/sdp, application/simple-message-summary, message/sipfrag Content-Length: 0 16:33:42 2663048707mS SIP Tx: UDP 10.1.0.21:5060 -> 192.168.1.108:5060 SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.1.108:5060;branch=z9hG4bKac30463710 From: ;tag=1c30427417 Call-ID: 30423497199201723350@192.168.1.108 CSeq: 1 OPTIONS Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,INFO,REFER,NOTIFY,UPDATE Supported: timer Server: IP Office 9.1.6.0 build 153 To: ;tag=812b805c289efa30 Content-Type: application/sdp Content-Length: 232 v=0 o=UserA 264612575 3202756569 IN IP4 0.0.0.0 s=Session SDP c=IN IP4 0.0.0.0 t=0 0 m=audio 8000 RTP/AVP 0 8 18 4 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:4 G723/16000 16:33:42 2663048709mS RES: Mon 18/9/2017 16:33:42 FreeMem=47639936 Heap=45474844(1) Cache=2165092 MemObjs=33877(36418) CMMsg=8(9) ASN=0 Buff=5200 1359 1000 7364 5 Links=85100(85971) BTree=3349(6936) CPU=18.01% CPUStats=17.33%/1/5/144/12337/15010/00.10%/1 /02.77% MCR=0 MCW=0 16:33:42 2663048710mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=52 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=94 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=50(TLS=5) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034 16:33:42 2663048710mS RES4: XML MemObjs=63 PoolMem=5796992(3) FreePoolMem=5781688(0) 16:33:42 2663048710mS RES5: CLog MemObjs=4866 FreePoolMem(Objs)=6968(134) TotalMem=704500 16:33:44 2663050522mS H323Evt: Recv: RegistrationRequest 192.168.252.133; Extn(495), time since last RRQ-KA 55044, Endpoints registered: 13; Endpoints in registration: 0 16:33:44 2663050537mS H323Evt: Recv: RegistrationRequest 192.168.252.137; Extn(609), time since last RRQ-KA 55048, Endpoints registered: 13; Endpoints in registration: 0 16:33:44 2663050543mS H323Evt: Recv: RegistrationRequest 192.168.252.135; Extn(605), time since last RRQ-KA 55042, Endpoints registered: 13; Endpoints in registration: 0 16:33:47 2663053090mS H323Evt: Recv: RegistrationRequest 192.168.1.102; Extn(250), time since last RRQ-KA 55011, Endpoints registered: 13; Endpoints in registration: 0 16:33:47 2663053712mS RES: Mon 18/9/2017 16:33:47 FreeMem=47685372 Heap=45507632(1) Cache=2177740 MemObjs=33739(36418) CMMsg=8(9) ASN=0 Buff=5200 1359 1000 7364 5 Links=85104(85971) BTree=3349(6936) CPU=17.69% CPUStats=17.23%/1/5/144/12331/15010/00.14%/1 /02.77% MCR=0 MCW=0 16:33:47 2663053712mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=52 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=93 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=50(TLS=5) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034 16:33:47 2663053712mS RES4: XML MemObjs=63 PoolMem=5796992(3) FreePoolMem=5781688(0) 16:33:47 2663053712mS RES5: CLog MemObjs=4866 FreePoolMem(Objs)=6968(134) TotalMem=704500 16:33:53 2663059226mS PRN: Optimizing BTree Lists Completed...Started:2663059225 Duration:1 Size:384 Attempted:384 16:33:59 2663065082mS CMCallEvt: 0000000000000000 0.660877.0 -1 BaseEP: NEW CMEndpoint f487b9e4 TOTAL NOW=7 CALL_LIST=3 16:33:59 2663065082mS CMCallEvt: 0000000000000000 0.660877.0 -1 cgoretski.-1: NEW CMExtnEndpoint f487b9e4, Name=cgoretski, Extn=381, Phys Extn=381 16:33:59 2663065083mS CMCallEvt: CREATE CALL:180679 (f1740e5c) 16:33:59 2663065083mS CMCallEvt: 0000000000000000 0.660878.0 -1 BaseEP: NEW CMEndpoint f171e7e8 TOTAL NOW=8 CALL_LIST=3 16:33:59 2663065085mS CMExtnEvt: cgoretski: CMExtnHandler::SetCurrent( id: 0->660877 ) 16:33:59 2663065085mS CMExtnRx: v=381, p1=0 CMSetup Line: type=DigitalExtn 8 Call: lid=0 id=660877 in=0 Called[] Type=Default (100) Reason=CMDRdirect Calling[381] Type=Internal Plan=Default BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw IE CMIECallingPartyName (110)(Type=CMNameDefault) name=cgoretski IE CMIECallingPartyKName (226)(Type=CMNameDefault) name=Cherie Goretski 16:33:59 2663065086mS CMCallEvt: c0a8000a000a158d 0.660877.0 180679 cgoretski.0: StateChange: END=A CMCSIdle->CMCSDialInitiated 16:33:59 2663065086mS CMExtnEvt: v=24 State, new=Dialling old=Idle,0,0,cgoretski 16:33:59 2663065087mS CMTARGET: c0a8000a000a158d 0.660877.0 180679 cgoretski.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party= sub= calling=381 calling_sub= dir=out complete=0 ses=0 16:33:59 2663065087mS CMTARGET: c0a8000a000a158d 0.660877.0 180679 cgoretski.0: ADD TARGET (N): number= type=100 depth=1 nobar=1 setorig=1 ses=0 16:33:59 2663065087mS CMCallEvt: c0a8000a000a158d 0.660877.0 180679 cgoretski.0: StateChange: END=A CMCSDialInitiated->CMCSDialling 16:33:59 2663065088mS CMExtnTx: v=381, p1=0 CMSetupAck Line: type=DigitalExtn 8 Call: lid=0 id=660877 in=0 BChan: slot=10 chan=26 Timed: 18/09/17 16:33 16:33:59 2663065090mS CD: CALL: 0.660877.0 BState=Idle Cut=1 Music=3.0 Aend="cgoretski(381)" (10.26) Bend="" [] (0.0) CalledNum= () CallingNum=381 (cgoretski) Internal=1 Time=8 AState=DialInitiated 16:33:59 2663065091mS CMMap: a=10.26 b=0.0 D1 16:33:59 2663065213mS RES: Mon 18/9/2017 16:33:58 FreeMem=47658500 Heap=45507632(1) Cache=2150868 MemObjs=33764(36418) CMMsg=8(9) ASN=0 Buff=5200 1359 1000 7363 5 Links=85110(85971) BTree=3352(6936) CPU=16.96% CPUStats=17.81%/10/16/144/12092/15010/00.22% /1/02.83% MCR=0 MCW=0 16:33:59 2663065213mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=52 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=96 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=50(TLS=5) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034 16:33:59 2663065213mS RES4: XML MemObjs=63 PoolMem=5796992(3) FreePoolMem=5781688(0) 16:33:59 2663065213mS RES5: CLog MemObjs=4866 FreePoolMem(Objs)=6968(134) TotalMem=704500 16:33:59 2663065441mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,381: Digit Key Pressed 3 16:33:59 2663065442mS CMExtnRx: v=381, p1=0 CMInformation Line: type=DigitalExtn 8 Call: lid=0 id=660877 in=0 Called[3] Type=Default (100) Reason=CMDRdirect Keypad[3] 16:33:59 2663065442mS CMTARGET: c0a8000a000a158d 0.660877.0 180679 cgoretski.0: Setting Hard Timer 4000 16:33:59 2663065442mS CMTARGET: c0a8000a000a158d 0.660877.0 180679 cgoretski.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=3 sub= calling=381 calling_sub= dir=out complete=0 ses=0 16:33:59 2663065443mS CMTARGET: c0a8000a000a158d 0.660877.0 180679 cgoretski.0: ADD TARGET (N): number=3 type=100 depth=1 nobar=1 setorig=1 ses=0 16:33:59 2663065445mS CMMap: a=10.26 b=0.0 D0 16:33:59 2663065792mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,381: Digit Key Pressed 4 16:33:59 2663065792mS CMExtnRx: v=381, p1=0 CMInformation Line: type=DigitalExtn 8 Call: lid=0 id=660877 in=0 Called[4] Type=Default (100) Reason=CMDRdirect Keypad[4] 16:33:59 2663065793mS CMTARGET: c0a8000a000a158d 0.660877.0 180679 cgoretski.0: Setting Hard Timer 4000 16:33:59 2663065793mS CMTARGET: c0a8000a000a158d 0.660877.0 180679 cgoretski.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=34 sub= calling=381 calling_sub= dir=out complete=0 ses=0 16:33:59 2663065793mS CMTARGET: c0a8000a000a158d 0.660877.0 180679 cgoretski.0: ADD TARGET (N): number=34 type=100 depth=1 nobar=1 setorig=1 ses=0 16:34:00 2663066167mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,381: Digit Key Pressed 3 16:34:00 2663066168mS CMExtnRx: v=381, p1=0 CMInformation Line: type=DigitalExtn 8 Call: lid=0 id=660877 in=0 Called[3] Type=Default (100) Reason=CMDRdirect Keypad[3] 16:34:00 2663066168mS CMTARGET: c0a8000a000a158d 0.660877.0 180679 cgoretski.0: Setting Hard Timer 4000 16:34:00 2663066168mS CMTARGET: c0a8000a000a158d 0.660877.0 180679 cgoretski.0: LOOKUP CALL ROUTE: GID=0 type=100 called_party=343 sub= calling=381 calling_sub= dir=out complete=0 ses=0 16:34:00 2663066168mS CMTARGET: c0a8000a000a158d 0.660877.0 180679 cgoretski.0: ADD TARGET (N): number=343 type=100 depth=1 nobar=1 setorig=1 ses=0 16:34:00 2663066169mS CMTARGET: c0a8000a000a158d 0.660877.0 180679 cgoretski.0: SET USER: rkrueger orig=1 16:34:00 2663066169mS CMTARGET: c0a8000a000a158d 0.660877.0 180679 cgoretski.0: ADD USER: rkrueger depth=1 disallow_cw=0 dnd=0 real_call=1 group_call=0 type(CMNTypeDefault) incl(0x0) excpt(0x0), allow_redir(1) remote=00000000 simult 0 (0) 16:34:00 2663066169mS CMCallEvt: 0000000000000000 0.660879.0 -1 BaseEP: NEW CMEndpoint f485aff0 TOTAL NOW=9 CALL_LIST=4 16:34:00 2663066170mS CMCallEvt: 0000000000000000 0.660879.0 -1 rkrueger.-1: NEW CMExtnEndpoint f485aff0, Name=rkrueger, Extn=343, Phys Extn=343 16:34:00 2663066171mS CMTARGET: c0a8000a000a158f 0.660879.0 180679 rkrueger.0: ADD PRIMARY 16:34:00 2663066171mS CMTARGET: c0a8000a000a158d 0.660877.0 180679 cgoretski.0: CancelTimer CMTCDelayedProcessing 16:34:00 2663066171mS CMTARGET: c0a8000a000a158d 0.660877.0 180679 cgoretski.0: INITIAL TARGETING SUCCEEDED 16:34:00 2663066171mS CMTARGET: c0a8000a000a158d 0.660877.0 180679 cgoretski.0: GetNoAnswerTimer:15 16:34:00 2663066172mS CMCallEvt: 0000000000000000 0.660878.0 180679 TargetingEP: StateChange: END=B CMCSIdle->CMCSOffering 16:34:00 2663066173mS CMCallEvt: c0a8000a000a158f 0.660879.0 180679 rkrueger.0: StateChange: END=T CMCSIdle->CMCSOffering 16:34:00 2663066173mS CMExtnEvt: rkrueger: CMExtnHandler::SetCurrent( id: 0->660879 ) 16:34:00 2663066173mS CMExtnTx: v=343, p1=0 CMSetup Line: type=DigitalExtn 8 Call: lid=0 id=660879 in=0 Called[343] Type=Default (100) Reason=CMDRdirect Calling[381] Type=Internal Plan=Default BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw IE CMIECallingPartyName (110)(Type=CMNameDefault) name=cgoretski IE CMIECalledPartyName (224)(Type=CMNameDefault) name=rkrueger IE CMIECalledPartyKName (225)(Type=CMNameDefault) name=Renee Krueger IE CMIECallingPartyKName (226)(Type=CMNameDefault) name=Cherie Goretski IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=cgoretski IE CMIERespondingPartyKName (229)(Type=CMNameDefault) name=Cherie Goretski IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=381 IE CMIEDeviceDetail (231) c0a8000a000a158d LOCALE=enu HW=15 VER=9 class=CMDeviceStdPhone type=109 number=324 channel=0 features=0x10000420 rx_gain=32 tx_gain=32 ep_callid=660877 ipaddr=192.168.0.10 apps=0 loc=0 em_loc=1 features2=0x0 is_spcall =0 IE CMIEMohSourceId (247) MOH Source = 255 Display [cgoretski>rkrueger] Timed: 18/09/17 16:33 Locale: enu 16:34:00 2663066174mS CMExtnRx: v=343, p1=0 CMAlerting Line: type=DigitalExtn 8 Call: lid=0 id=660879 in=0 16:34:00 2663066174mS CMCallEvt: c0a8000a000a158f 0.660879.0 180679 rkrueger.0: StateChange: END=T CMCSOffering->CMCSRinging 16:34:00 2663066174mS CMExtnEvt: v=2 State, new=Ringing old=Idle,0,0,rkrueger 16:34:00 2663066175mS CMCallEvt: 0000000000000000 0.660878.0 180679 TargetingEP: StateChange: END=B CMCSOffering->CMCSRinging 16:34:00 2663066175mS CMCallEvt: c0a8000a000a158d 0.660877.0 180679 cgoretski.0: StateChange: END=A CMCSDialling->CMCSRingBack 16:34:00 2663066176mS CMExtnEvt: v=24 State, new=Alerting old=Dialling,0,0,cgoretski 16:34:00 2663066176mS CMExtnTx: v=381, p1=0 CMAlerting Line: type=DigitalExtn 8 Call: lid=0 id=660877 in=0 IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=rkrueger IE CMIERespondingPartyKName (229)(Type=CMNameDefault) name=Renee Krueger IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=343 IE CMIEDeviceDetail (231) c0a8000a000a158f LOCALE=enu HW=15 VER=9 class=CMDeviceStdPhone type=109 number=302 channel=0 features=0x10000400 rx_gain=32 tx_gain=32 ep_callid=660879 ipaddr=192.168.0.10 apps=0 loc=0 em_loc=1 features2=0x0 is_spcall =0 Timed: 18/09/17 16:33 16:34:00 2663066178mS CD: CALL: 0.660877.0 BState=Ringing Cut=1 Music=2.0 Aend="cgoretski(381)" (10.26) Bend="rkrueger(343)" [rkrueger(343)] (0.0) CalledNum=343 (rkrueger) CallingNum=381 (cgoretski) Internal=1 Time=1096 AState=Ringing 16:34:00 2663066179mS CMMap: a=10.26 b=0.0 R1 16:34:10 2663076171mS CMTARGET: c0a8000a000a158d 0.660877.0 180679 cgoretski.0: TimerExpired cause=CMTCCoverageTimeout 16:34:10 2663076171mS CMTARGET: c0a8000a000a158d 0.660877.0 180679 cgoretski.0: GetNoAnswerTimer:15 16:34:15 2663081171mS CMTARGET: c0a8000a000a158d 0.660877.0 180679 cgoretski.0: TimerExpired cause=CMTCNoAnswerTimeout 16:34:15 2663081171mS CMTARGET: c0a8000a000a158d 0.660877.0 180679 cgoretski.0: Retarget NOANSWER EXCEPTED=00000001 INCLUDED=00000001 ValidTargets=0 16:34:15 2663081171mS CMTARGET: c0a8000a000a158d 0.660877.0 180679 cgoretski.0: Retarget on target_cfg_user=rkrueger 16:34:15 2663081171mS CMTARGET: c0a8000a000a158d 0.660877.0 180679 cgoretski.0: ADD USER: rkrueger depth=1 disallow_cw=0 dnd=0 real_call=1 group_call=0 type(CMNTypeDefault) incl(0x1) excpt(0x1), allow_redir(1) remote=00000000 simult 0 (0) 16:34:15 2663081172mS CMTARGET: c0a8000a000a158d 0.660877.0 180679 cgoretski.0: SELECT: TRY VOICEMAIL orig_hg() orig_user(343) 16:34:15 2663081172mS CMTARGET: c0a8000a000a158d 0.660877.0 180679 cgoretski.0: ADD VM TARGET 16:34:15 2663081172mS CMTARGET: c0a8000a000a158d 0.660877.0 180679 cgoretski.0: MakeVoicemailTarget pbx= local=1 type=1 16:34:15 2663081173mS CMCallEvt: 0000000000000000 0.660880.0 -1 BaseEP: NEW CMEndpoint f4845e34 TOTAL NOW=10 CALL_LIST=4 16:34:15 2663081173mS CMTARGET: c0a8000a000a1590 0.660880.0 180679 RAS.0: ADD PRIMARY 16:34:15 2663081173mS CMTARGET: c0a8000a000a158d 0.660877.0 180679 cgoretski.0: ADD VM TARGET: SUCCEEDED 16:34:15 2663081174mS CMTARGET: c0a8000a000a158d 0.660877.0 180679 cgoretski.0: GetNoAnswerTimer:15 16:34:15 2663081175mS CMCallEvt: c0a8000a000a1590 0.660880.0 180679 RAS.0: StateChange: END=T CMCSIdle->CMCSOffering 16:34:15 2663081175mS CMExtnEvt: RAS: CMExtnHandler::SetCurrent( id: 0->660880 ) 16:34:15 2663081175mS CMExtnTx: v=RAS, p1=0 CMSetup Line: type=RAS 1 Call: lid=0 id=1013 in=0 Called[#rkrueger] Type=Voicemail (102) Reason=107 Calling[381] Type=Internal Plan=Default BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw BChan: slot=21 chan=43 IE CMIECallingPartyName (110)(Type=CMNameDefault) name=cgoretski IE CMIECalledPartyName (224)(Type=CMNameDefault) name=rkrueger IE CMIECalledPartyKName (225)(Type=CMNameDefault) name=Renee Krueger IE CMIECallingPartyKName (226)(Type=CMNameDefault) name=Cherie Goretski IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=cgoretski IE CMIERespondingPartyKName (229)(Type=CMNameDefault) name=Cherie Goretski IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=381 IE CMIEDeviceDetail (231) c0a8000a000a158d LOCALE=enu HW=15 VER=9 class=CMDeviceStdPhone type=109 number=324 channel=0 features=0x10000420 rx_gain=32 tx_gain=32 ep_callid=660877 ipaddr=192.168.0.10 apps=0 loc=0 em_loc=1 features2=0x0 is_spcall =0 IE CMIERedirectingPartyName (232)(Type=CMNameDefault) name=rkrueger IE CMIERedirectingPartyKName (233)(Type=CMNameDefault) name=Renee Krueger IE CMIERedirectingPartyNumber (234)(P:100 S:100 T:101 N:100 R:3) number=343 IE CMIEOriginalCalledPartyName (236)(Type=CMNameDefault) name=rkrueger IE CMIEOriginalCalledPartyKName (237)(Type=CMNameDefault) name=Renee Krueger IE CMIEOriginalCalledPartyNumber (238)(P:100 S:100 T:101 N:100 R:3) number=343 IE CMIEMohSourceId (247) MOH Source = 255 Display [cgoretski>rkrueger] Timed: 18/09/17 16:34 Locale: enu 16:34:15 2663081176mS CMMap: a=21.43 b=1.65534 T 16:34:15 2663081177mS CMExtnRx: v=RAS, p1=0 CMConnect Line: type=NoLine 0 Call: lid=0 id=-1 in=0 IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=#rkrueger IE CMIERespondingPartyNumber (230)(P:100 S:100 T:102 N:100 R:4) number= IE CMIEDeviceDetail (231) c0a8000a000a1590 LOCALE=enu HW=15 VER=9 class=CMDeviceVoicemail type=0 number=0 channel=43 features=0x0 rx_gain=32 tx_gain=32 ep_callid=660880 ipaddr=192.168.0.10 apps=0 loc=0 em_loc=0 features2=0x0 is_spcall=0 IE CMIERedirectingPartyName (232)(Type=CMNameDefault) name=rkrueger IE CMIERedirectingPartyKName (233)(Type=CMNameDefault) name=Renee Krueger IE CMIERedirectingPartyNumber (234)(P:100 S:100 T:101 N:100 R:3) number=343 16:34:15 2663081177mS CMCallEvt: c0a8000a000a1590 0.660880.0 180679 RAS.0: StateChange: END=T CMCSOffering->CMCSConnReq 16:34:15 2663081178mS CMCallEvt: 0000000000000000 0.660878.0 180679 TargetingEP: RequestEnd c0a8000a000a1590 0.660880.0 180679 RAS.0 16:34:15 2663081178mS CMTARGET: c0a8000a000a158d 0.660877.0 180679 cgoretski.0: CancelTimer CMTCNoAnswerTimeout 16:34:15 2663081179mS CMExtnEvt: rkrueger: CALL LOST (CMCauseForwardToVoicemail) 16:34:15 2663081179mS CMExtnEvt: rkrueger: Extn(343) Calling Party Number(381) Type(CMNTypeInternal) 16:34:15 2663081179mS CMCallEvt: c0a8000a000a158f 0.660879.0 -1 rkrueger.0: StateChange: END=X CMCSRinging->CMCSCompleted 16:34:15 2663081179mS CMExtnEvt: v=2 State, new=PortRecoverDelay old=Ringing,0,0,rkrueger 16:34:15 2663081180mS CMExtnTx: v=343, p1=0 CMReleaseComp Line: type=DigitalExtn 8 Call: lid=0 id=660879 in=0 Called[343] Type=Default (100) Reason=CMDRdirect Calling[381] Type=Internal Plan=Default Cause=123, Forward To Voicemail(IPO) Timed: 18/09/17 16:34 16:34:15 2663081180mS CMExtnEvt: rkrueger: CMExtnHandler::SetCurrent( id: 660879->0 ) 16:34:15 2663081181mS CMCallEvt: c0a8000a000a158f 0.660879.0 -1 rkrueger.-1: StateChange: END=X CMCSCompleted->CMCSDelete 16:34:15 2663081181mS CMExtnEvt: v=2 State, new=Idle old=PortRecoverDelay,0,0,rkrueger 16:34:15 2663081182mS CMCallEvt: c0a8000a000a158f 0.660879.0 -1 BaseEP: DELETE CMEndpoint f485aff0 TOTAL NOW=9 CALL_LIST=4 16:34:15 2663081182mS CMExtnEvt: v=1013 State, new=Connected old=Idle,0,0,RAS 16:34:15 2663081182mS CMCallEvt: c0a8000a000a158d 0.660877.0 180679 cgoretski.0: StateChange: END=A CMCSRingBack->CMCSOGConnReq 16:34:15 2663081182mS CMExtnEvt: v=24 State, new=Connected old=Alerting,0,0,cgoretski 16:34:15 2663081183mS CMExtnTx: v=381, p1=0 CMConnect Line: type=DigitalExtn 8 Call: lid=0 id=660877 in=0 IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=#rkrueger IE CMIERespondingPartyNumber (230)(P:100 S:100 T:102 N:100 R:4) number= IE CMIEDeviceDetail (231) c0a8000a000a1590 LOCALE=enu HW=15 VER=9 class=CMDeviceVoicemail type=0 number=0 channel=43 features=0x0 rx_gain=32 tx_gain=32 ep_callid=660880 ipaddr=192.168.0.10 apps=0 loc=0 em_loc=0 features2=0x0 is_spcall=0 IE CMIERedirectingPartyName (232)(Type=CMNameDefault) name=rkrueger IE CMIERedirectingPartyKName (233)(Type=CMNameDefault) name=Renee Krueger IE CMIERedirectingPartyNumber (234)(P:100 S:100 T:101 N:100 R:3) number=343 Timed: 18/09/17 16:34 16:34:15 2663081183mS CMExtnRx: v=381, p1=0 CMConnectAck Line: type=DigitalExtn 8 Call: lid=0 id=660877 in=0 16:34:15 2663081183mS CMCallEvt: c0a8000a000a158d 0.660877.0 180679 cgoretski.0: StateChange: END=A CMCSOGConnReq->CMCSConnected 16:34:15 2663081184mS CMTARGET: c0a8000a000a158d 0.660877.0 180679 cgoretski.0: ~CMTargetHandler f1717bbc ep f487b9e4 16:34:15 2663081185mS CMCallEvt: c0a8000a000a1590 0.660880.0 180679 RAS.0: StateChange: END=B CMCSConnReq->CMCSConnected 16:34:15 2663081185mS CMExtnTx: v=RAS, p1=0 CMConnectAck Line: type=RAS 1 Call: lid=0 id=1013 in=0 BChan: slot=21 chan=43 IE CMIERespondingPartyName (228)(Type=CMNameDefault) name=cgoretski IE CMIERespondingPartyKName (229)(Type=CMNameDefault) name=Cherie Goretski IE CMIERespondingPartyNumber (230)(P:100 S:100 T:101 N:100 R:4) number=381 IE CMIEDeviceDetail (231) c0a8000a000a158d LOCALE=enu HW=15 VER=9 class=CMDeviceStdPhone type=109 number=324 channel=0 features=0x10000420 rx_gain=32 tx_gain=32 ep_callid=660877 ipaddr=192.168.0.10 apps=0 loc=0 em_loc=1 features2=0x0 is_spcall =0 16:34:15 2663081186mS CMCallEvt: 0000000000000000 0.660878.0 -1 BaseEP: DELETE CMEndpoint f171e7e8 TOTAL NOW=8 CALL_LIST=4 16:34:15 2663081186mS CD: CALL: 0.660877.0 BState=Connected Cut=3 Music=0.0 Aend="cgoretski(381)" (10.26) Bend="rkrueger(343)" [VoiceMail] (21.43) CalledNum=#rkrueger (rkrueger) CallingNum=381 (cgoretski) Internal=1 Time=16104 AState=Connected 16:34:15 2663081188mS PRN: Config Write Wake Up 16:34:15 2663081188mS CMMap: a=10.26 b=0.0 R0 16:34:15 2663081189mS CMMap: PCG::MapBChan pcp[238]b1r0 cp_b f496b938 other_cp_b 0 type CGTypeSimple 16:34:15 2663081189mS CMMap: PCG::MapBChan pcp[24]b1r0 cp_b f5396e58 other_cp_b f496b938 type CGTypeSimple 16:34:15 2663081189mS CMMap: a=10.26 b=21.43 M12 16:34:15 2663081202mS CMExtnRx: v=RAS, p1=0 CMVoiceMailMsg Line: type=NoLine 0 Call: lid=0 id=-1 in=0 Called[LeaveMessage] Type=Default (100) Reason=CMDRdirect Calling SubAddress[0] Tag type=Text flags=0x1 [1.] [0x31 0x00 ] 16:34:15 2663081202mS CMExtnTx: v=381, p1=0 CMVoiceMailMsg Line: type=DigitalExtn 8 Call: lid=0 id=660877 in=0 Called[LeaveMessage] Type=Default (100) Reason=CMDRdirect Calling SubAddress[0] Tag type=Text flags=0x1 [1.] [0x31 0x00 ] Timed: 18/09/17 16:34 16:34:15 2663081227mS RES: Mon 18/9/2017 16:34:14 FreeMem=47658864 Heap=45507632(1) Cache=2151232 MemObjs=33789(36418) CMMsg=8(9) ASN=0 Buff=5200 1358 997 7363 5 Links=85125(85971) BTree=3354(6936) CPU=16.90% CPUStats=18.20%/16/26/144/11922/15010/00.13%/ 0/02.80% MCR=0 MCW=0 16:34:15 2663081228mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=52 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=116 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=50(TLS=5) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034 16:34:15 2663081228mS RES4: XML MemObjs=63 PoolMem=5796992(3) FreePoolMem=5781688(0) 16:34:15 2663081228mS RES5: CLog MemObjs=4866 FreePoolMem(Objs)=6968(134) TotalMem=704500 16:34:15 2663081689mS PRN: Updates IO list size 1 updated list size 1 16:34:15 2663081691mS PRN: Sending Updates out to f497c45c started 16:34:15 2663081691mS PRN: Sending Updates out to f497c45c finished 16:34:15 2663081692mS PRN: Config Write Completed 16:34:15 2663082510mS H323Evt: Recv: RegistrationRequest 192.168.1.103; Extn(251), time since last RRQ-KA 55011, Endpoints registered: 13; Endpoints in registration: 0 16:34:18 2663085460mS CMExtnRx: v=381, p1=0 CMReleaseComp Line: type=DigitalExtn 8 Call: lid=0 id=660877 in=0 16:34:18 2663085461mS CMCallEvt: c0a8000a000a158d 0.660877.0 180679 cgoretski.0: StateChange: END=A CMCSConnected->CMCSCompleted 16:34:18 2663085462mS CMExtnEvt: v=24 State, new=PortRecoverDelay old=Connected,0,0,cgoretski 16:34:18 2663085463mS CMLOGGING: CALL:2017/09/1816:33,00:00:04,015,381,O,343,343,cgoretski,,,1,,"",0,n/a 16:34:18 2663085464mS CD: CALL: 0.660877.0 BState=Connected Cut=2 Music=0.0 Aend="cgoretski(381)" (10.26) Bend="rkrueger(343)" [VoiceMail] (21.43) CalledNum=#rkrueger (rkrueger) CallingNum=381 (cgoretski) Internal=1 Time=20381 AState=Idle 16:34:18 2663085464mS CD: CALL: 0.660877.0 Deleted 16:34:18 2663085464mS CMExtnEvt: cgoretski: CALL LOST (CMCauseNormal) 16:34:18 2663085464mS CMExtnEvt: cgoretski: Extn(381) Calling Party Number(381) Type(CMNTypeInternal) 16:34:18 2663085464mS CMExtnEvt: cgoretski: CMExtnHandler::SetCurrent( id: 660877->0 ) 16:34:18 2663085465mS CMCallEvt: c0a8000a000a158d 0.660877.0 -1 cgoretski.-1: StateChange: END=X CMCSCompleted->CMCSDelete 16:34:18 2663085466mS CMExtnEvt: RAS: CALL LOST (CMCauseNormal) 16:34:18 2663085466mS CMCallEvt: c0a8000a000a1590 0.660880.0 -1 RAS.0: StateChange: END=X CMCSConnected->CMCSCompleted 16:34:18 2663085466mS CMExtnEvt: v=1013 State, new=PortRecoverDelay old=Connected,0,0,RAS 16:34:18 2663085466mS CMExtnTx: v=RAS, p1=0 CMReleaseComp Line: type=RAS 1 Call: lid=0 id=1013 in=0 Called[#rkrueger] Type=Voicemail (102) Reason=107 Calling[381] Type=Internal Plan=Default BChan: slot=21 chan=43 Cause=16, Normal call clearing 16:34:18 2663085467mS CMMap: a=21.43 b=0.0 T0 16:34:18 2663085468mS CMExtnEvt: RAS: CMExtnHandler::SetCurrent( id: 660880->0 ) 16:34:18 2663085468mS CMCallEvt: c0a8000a000a1590 0.660880.0 -1 RAS.-1: StateChange: END=X CMCSCompleted->CMCSDelete 16:34:18 2663085469mS CMExtnEvt: v=1013 State, new=Idle old=PortRecoverDelay,0,0,RAS 16:34:18 2663085469mS CMExtnTx: v=RAS, p1=0 CMReleaseComp Line: type=RAS 1 Call: lid=0 id=1013 in=0 BChan: slot=21 chan=43 Cause=16, Normal call clearing 16:34:18 2663085469mS CMCallEvt: c0a8000a000a1590 0.660880.0 -1 BaseEP: DELETE CMEndpoint f4845e34 TOTAL NOW=7 CALL_LIST=3 16:34:18 2663085469mS CMCallEvt: END CALL:180679 (f1740e5c) 16:34:18 2663085470mS CMCallEvt: c0a8000a000a158d 0.660877.0 -1 BaseEP: DELETE CMEndpoint f487b9e4 TOTAL NOW=6 CALL_LIST=3 16:34:18 2663085473mS CMMap: PCG::UnmapBChan pcp[24]b1r0 cp_b f5396e58 other_cp_b f496b938 16:34:18 2663085473mS CMMap: a=10.26 b=21.43 M02 16:34:18 2663085473mS CMMap: PCG::UnmapBChan pcp[238]b1r0 cp_b f496b938 other_cp_b 0 16:34:21 2663087465mS CMExtnEvt: cgoretski: Recover Timer reason=CMTRWrapUp 16:34:21 2663087465mS CMExtnEvt: v=24 State, new=Idle old=PortRecoverDelay,0,0,cgoretski 16:34:21 2663087466mS CMExtnTx: v=381, p1=0 CMVoiceMailStatus Line: type=DigitalExtn 8 Call: lid=0 id=-1 in=0 Called[cgoretski Msgs=0 Old=16 Sav=1] Type=Default (100) Reason=CMDRdirect Calling[00000000] Type=Default Plan=Default Display [cgoretski Msgs=0] Timed: 18/09/17 16:34 16:34:21 2663087825mS H323Evt: Recv: RegistrationRequest 192.168.1.106; Extn(254), time since last RRQ-KA 55011, Endpoints registered: 13; Endpoints in registration: 0 16:34:24 2663090757mS H323Evt: Recv: RegistrationRequest 192.168.1.105; Extn(253), time since last RRQ-KA 55012, Endpoints registered: 13; Endpoints in registration: 0 16:34:32 2663098562mS H323Evt: Recv: RegistrationRequest 192.168.252.132; Extn(601), time since last RRQ-KA 55042, Endpoints registered: 13; Endpoints in registration: 0 16:34:32 2663098660mS H323Evt: Recv: RegistrationRequest 192.168.252.139; Extn(612), time since last RRQ-KA 55040, Endpoints registered: 13; Endpoints in registration: 0 16:34:33 2663099106mS H323Evt: Recv: RegistrationRequest 192.168.252.136; Extn(606), time since last RRQ-KA 55042, Endpoints registered: 13; Endpoints in registration: 0 16:34:33 2663099970mS H323Evt: Recv: RegistrationRequest 192.168.1.104; Extn(252), time since last RRQ-KA 55011, Endpoints registered: 13; Endpoints in registration: 0 16:34:34 2663100036mS H323Evt: Recv: RegistrationRequest 192.168.252.134; Extn(604), time since last RRQ-KA 55045, Endpoints registered: 13; Endpoints in registration: 0 16:34:35 2663101958mS H323Evt: Recv: RegistrationRequest 192.168.252.138; Extn(611), time since last RRQ-KA 55042, Endpoints registered: 13; Endpoints in registration: 0 ********** SysMonitor v9.1.6.0 build 153 [connected to 192.168.0.10 (Huron County)] ********** 16:34:36 2663102626mS PRN: Monitor Status IP 500 V2 9.1.6.0 build 153 16:34:36 2663102627mS PRN: LAW=U PRI=2, BRI=0, ALOG=4, VCOMP=10, MDM=0, WAN=0, MODU=5 LANM=0 CkSRC=5 VMAIL=1(VER=3 TYP=1) 1-X=0 CALLS=3(TOT=180679) 16:34:38 2663104350mS CMExtnEvt: kkociba: No user activity 16:34:39 2663105564mS H323Evt: Recv: RegistrationRequest 192.168.252.133; Extn(495), time since last RRQ-KA 55042, Endpoints registered: 13; Endpoints in registration: 0 16:34:39 2663105583mS H323Evt: Recv: RegistrationRequest 192.168.252.137; Extn(609), time since last RRQ-KA 55046, Endpoints registered: 13; Endpoints in registration: 0 16:34:39 2663105588mS H323Evt: Recv: RegistrationRequest 192.168.252.135; Extn(605), time since last RRQ-KA 55045, Endpoints registered: 13; Endpoints in registration: 0 16:34:41 2663108101mS H323Evt: Recv: RegistrationRequest 192.168.1.102; Extn(250), time since last RRQ-KA 55011, Endpoints registered: 13; Endpoints in registration: 0 16:34:41 2663108782mS SIP Rx: UDP 192.168.1.108:5060 -> 10.1.0.21:5060 OPTIONS sip:9892693555@192.168.1.108 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.108:5060;branch=z9hG4bKac781418281 Max-Forwards: 70 From: ;tag=1c781391680 To: Call-ID: 781387760199201723450@192.168.1.108 CSeq: 1 OPTIONS Contact: Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE User-Agent: MP-124E FXS/v.6.60A.332.002 Accept: application/sdp, application/simple-message-summary, message/sipfrag Content-Length: 0 16:34:41 2663108787mS SIP Tx: UDP 10.1.0.21:5060 -> 192.168.1.108:5060 SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.1.108:5060;branch=z9hG4bKac781418281 From: ;tag=1c781391680 Call-ID: 781387760199201723450@192.168.1.108 CSeq: 1 OPTIONS Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,INFO,REFER,NOTIFY,UPDATE Supported: timer Server: IP Office 9.1.6.0 build 153 To: ;tag=2fce8a5d27cda35f Content-Type: application/sdp Content-Length: 232 v=0 o=UserA 3150540549 480137680 IN IP4 0.0.0.0 s=Session SDP c=IN IP4 0.0.0.0 t=0 0 m=audio 8000 RTP/AVP 0 8 18 4 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:4 G723/16000 16:34:42 2663109155mS RES: Mon 18/9/2017 16:34:42 FreeMem=47640164 Heap=45474844(1) Cache=2165320 MemObjs=33875(36418) CMMsg=8(9) ASN=0 Buff=5200 1359 1000 7364 5 Links=85111(85971) BTree=3352(6936) CPU=18.17% CPUStats=17.81%/6/10/144/12080/15010/00.13%/ 0/02.78% MCR=0 MCW=0 16:34:42 2663109155mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=52 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=94 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=50(TLS=5) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034 16:34:42 2663109155mS RES4: XML MemObjs=63 PoolMem=5796992(3) FreePoolMem=5781688(0) 16:34:42 2663109155mS RES5: CLog MemObjs=4866 FreePoolMem(Objs)=6968(134) TotalMem=704500 16:34:47 2663114157mS RES: Mon 18/9/2017 16:34:47 FreeMem=47685376 Heap=45507632(1) Cache=2177744 MemObjs=33739(36418) CMMsg=8(9) ASN=0 Buff=5200 1359 1000 7364 5 Links=85108(85971) BTree=3352(6936) CPU=17.96% CPUStats=17.42%/1/5/144/12202/15010/00.11%/0 /02.72% MCR=0 MCW=0 16:34:47 2663114157mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=52 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=93 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=50(TLS=5) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034 16:34:47 2663114157mS RES4: XML MemObjs=63 PoolMem=5796992(3) FreePoolMem=5781688(0) 16:34:47 2663114157mS RES5: CLog MemObjs=4866 FreePoolMem(Objs)=6968(134) TotalMem=704500 16:34:52 2663119228mS PRN: Optimizing BTree Lists Completed...Started:2663119227 Duration:1 Size:384 Attempted:384 16:35:07 2663134127mS CMExtnRx: v=224, p1=0 CMReleaseComp Line: type=DigitalExtn 6 Call: lid=0 id=660876 in=0 16:35:07 2663134128mS CMCallEvt: c0a8000a000a158c 0.660876.0 180678 kkociba.0: StateChange: END=B CMCSConnected->CMCSCompleted 16:35:07 2663134128mS CMExtnEvt: v=11 State, new=PortRecoverDelay old=Connected,0,0,kkociba 16:35:07 2663134130mS CMLOGGING: CALL:2017/09/1816:33,00:01:29,002,519899752158,I,766,9892696500,WIRELESSCALLER,,,0,,"",0,n/a 16:35:07 2663134130mS CD: CALL: 6.12.1 BState=Disconnecting Cut=1 Music=0.0 Aend="Line 6" (3.34) Bend="" [kkociba(224)] (8.13) CalledNum=766 (Sheriff Records) CallingNum=519899752158 (WIRELESS CALLER) Internal=0 Time=91952 AState=Connected 16:35:07 2663134130mS CD: CALL: 6.12.1 Deleted 16:35:07 2663134132mS CMLineTx: v=6 CMDisconnect Line: type=Q931Line 6 Call: lid=6 id=12 in=1 Cause=16, Normal call clearing 16:35:07 2663134132mS CMCallEvt: c0a8000a0000000c 6.12.1 -1 Q931 Trunk:6 CHAN=1: StateChange: END=X CMCSConnected->CMCSCompleted 16:35:07 2663134132mS CMExtnEvt: kkociba: CALL LOST (CMCauseNormal) 16:35:07 2663134132mS CMExtnEvt: kkociba: Extn(224) Calling Party Number(519899752158) Type(CMNTypeUnknown) 16:35:07 2663134132mS CMExtnEvt: kkociba: CMExtnHandler::SetCurrent( id: 660876->0 ) 16:35:07 2663134133mS CMCallEvt: c0a8000a000a158c 0.660876.0 -1 kkociba.-1: StateChange: END=X CMCSCompleted->CMCSDelete 16:35:07 2663134133mS CMCallEvt: END CALL:180678 (f16b82e8) 16:35:07 2663134134mS CMCallEvt: c0a8000a000a158c 0.660876.0 -1 BaseEP: DELETE CMEndpoint f48291a8 TOTAL NOW=5 CALL_LIST=2 16:35:07 2663134137mS CMMap: PCG::UnmapBChan pcp[95]b1r0 cp_b f52161c4 other_cp_b f4a77be4 16:35:07 2663134137mS CMMap: a=8.13 b=3.34 M02 16:35:07 2663134137mS CMMap: PCG::UnmapBChan pcp[180]b1r0 cp_b f4a77be4 other_cp_b 0 16:35:07 2663134138mS ISDNL3Evt: v=6 stacknum=6 State, new=DiscReq, old=Active id=12 16:35:07 2663134146mS ISDNL3Evt: v=6 stacknum=6 State, new=NullState, old=DiscReq id=12 16:35:07 2663134147mS CMLineRx: v=6 CMReleaseComp Line: type=Q931Line 6 Call: lid=6 id=12 in=1 BChan: slot=0 chan=1 16:35:07 2663134147mS CMCallEvt: c0a8000a0000000c 6.12.1 -1 Q931 Trunk:6 CHAN=1: StateChange: END=X CMCSCompleted->CMCSDelete 16:35:07 2663134147mS CMTARGET: ISDN BChannel 1: in-service check = 1 16:35:07 2663134147mS CMTARGET: ISDN BChannel 1: in-service check = 1 16:35:07 2663134148mS CMCallEvt: c0a8000a0000000c 6.12.1 -1 BaseEP: DELETE CMEndpoint f4818aac TOTAL NOW=4 CALL_LIST=2 16:35:07 2663134175mS RES: Mon 18/9/2017 16:35:07 FreeMem=47708900 Heap=45507632(1) Cache=2201268 MemObjs=33694(36418) CMMsg=8(9) ASN=0 Buff=5200 1359 999 7363 5 Links=85095(85971) BTree=3347(6936) CPU=17.82% CPUStats=18.88%/9/17/144/11942/15010/00.24%/1 /02.78% MCR=0 MCW=0 16:35:07 2663134175mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=52 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=100 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=50(TLS=5) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034 16:35:07 2663134175mS RES4: XML MemObjs=63 PoolMem=5796992(3) FreePoolMem=5781688(0) 16:35:07 2663134175mS RES5: CLog MemObjs=4866 FreePoolMem(Objs)=6968(134) TotalMem=704500 16:35:07 2663134501mS SIP Tx: UDP 10.1.0.21:5060 -> 192.168.1.108:5060 OPTIONS sip:192.168.1.108 SIP/2.0 Via: SIP/2.0/UDP 10.1.0.21:5060;rport;branch=z9hG4bK60f424d288e3e76fe7e08308323709bb From: ;tag=aa8403977791bc47 To: Call-ID: fe499b38b347749782663d9fc1731e43 CSeq: 643388730 OPTIONS Contact: Max-Forwards: 70 Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,INFO,REFER,NOTIFY,UPDATE Supported: timer User-Agent: IP Office 9.1.6.0 build 153 Content-Length: 0 16:35:07 2663134537mS SIP Rx: UDP 192.168.1.108:5060 -> 10.1.0.21:5060 SIP/2.0 200 OK Via: SIP/2.0/UDP 10.1.0.21:5060;branch=z9hG4bK60f424d288e3e76fe7e08308323709bb;received=10.1.0.21;rport=5060 From: ;tag=aa8403977791bc47 To: ;tag=1c1103282127 Call-ID: fe499b38b347749782663d9fc1731e43 CSeq: 643388730 OPTIONS Contact: ;expires=0 Supported: 100rel Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE Server: MP-124E FXS/v.6.60A.332.002 X-Resources: telchs=11/0;mediachs=0/0 Accept: application/sdp, application/simple-message-summary, message/sipfrag Content-Type: application/sdp Content-Length: 262 v=0 o=AudiocodesGW 1103304635 1103304630 IN IP4 192.168.1.108 s=Phone-Call c=IN IP4 192.168.1.108 t=0 0 m=audio 6000 RTP/AVP 8 0 101 a=ptime:20 a=sendrecv a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15,16 16:35:09 2663136133mS CMExtnEvt: kkociba: Recover Timer reason=CMTRWrapUp 16:35:09 2663136133mS CMExtnEvt: v=11 State, new=Idle old=PortRecoverDelay,0,0,kkociba 16:35:09 2663136134mS CMExtnTx: v=224, p1=0 CMVoiceMailStatus Line: type=DigitalExtn 6 Call: lid=0 id=-1 in=0 Called[kkociba Msgs=0 Old=5 Sav=0] Type=Default (100) Reason=CMDRdirect Calling[00000000] Type=Default Plan=Default Display [kkociba Msgs=0] Timed: 18/09/17 16:35 16:35:10 2663137520mS H323Evt: Recv: RegistrationRequest 192.168.1.103; Extn(251), time since last RRQ-KA 55010, Endpoints registered: 13; Endpoints in registration: 0 16:35:12 2663139680mS RES: Mon 18/9/2017 16:35:13 FreeMem=47708900 Heap=45507632(1) Cache=2201268 MemObjs=33694(36418) CMMsg=8(9) ASN=0 Buff=5200 1359 1000 7364 5 Links=85093(85971) BTree=3347(6936) CPU=17.84% CPUStats=17.81%/1/5/144/12143/15010/00.11%/0 /02.75% MCR=0 MCW=0 16:35:12 2663139680mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=52 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=94 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=50(TLS=5) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034 16:35:12 2663139680mS RES4: XML MemObjs=63 PoolMem=5796992(3) FreePoolMem=5781688(0) 16:35:12 2663139680mS RES5: CLog MemObjs=4866 FreePoolMem(Objs)=6968(134) TotalMem=704500 16:35:15 2663142835mS H323Evt: Recv: RegistrationRequest 192.168.1.106; Extn(254), time since last RRQ-KA 55010, Endpoints registered: 13; Endpoints in registration: 0 16:35:18 2663145471mS CMExtnEvt: cgoretski: No user activity 16:35:18 2663145768mS H323Evt: Recv: RegistrationRequest 192.168.1.105; Extn(253), time since last RRQ-KA 55011, Endpoints registered: 13; Endpoints in registration: 0 16:35:26 2663153604mS H323Evt: Recv: RegistrationRequest 192.168.252.132; Extn(601), time since last RRQ-KA 55042, Endpoints registered: 13; Endpoints in registration: 0 16:35:26 2663153702mS H323Evt: Recv: RegistrationRequest 192.168.252.139; Extn(612), time since last RRQ-KA 55042, Endpoints registered: 13; Endpoints in registration: 0 16:35:27 2663154147mS H323Evt: Recv: RegistrationRequest 192.168.252.136; Extn(606), time since last RRQ-KA 55041, Endpoints registered: 13; Endpoints in registration: 0 16:35:27 2663154981mS H323Evt: Recv: RegistrationRequest 192.168.1.104; Extn(252), time since last RRQ-KA 55011, Endpoints registered: 13; Endpoints in registration: 0 16:35:28 2663155081mS H323Evt: Recv: RegistrationRequest 192.168.252.134; Extn(604), time since last RRQ-KA 55045, Endpoints registered: 13; Endpoints in registration: 0 16:35:29 2663156999mS H323Evt: Recv: RegistrationRequest 192.168.252.138; Extn(611), time since last RRQ-KA 55041, Endpoints registered: 13; Endpoints in registration: 0 16:35:33 2663160610mS H323Evt: Recv: RegistrationRequest 192.168.252.133; Extn(495), time since last RRQ-KA 55046, Endpoints registered: 13; Endpoints in registration: 0 16:35:33 2663160625mS H323Evt: Recv: RegistrationRequest 192.168.252.137; Extn(609), time since last RRQ-KA 55042, Endpoints registered: 13; Endpoints in registration: 0 16:35:33 2663160630mS H323Evt: Recv: RegistrationRequest 192.168.252.135; Extn(605), time since last RRQ-KA 55042, Endpoints registered: 13; Endpoints in registration: 0 ********** SysMonitor v9.1.6.0 build 153 [connected to 192.168.0.10 (Huron County)] ********** 16:35:35 2663162633mS PRN: Monitor Status IP 500 V2 9.1.6.0 build 153 16:35:35 2663162633mS PRN: LAW=U PRI=2, BRI=0, ALOG=4, VCOMP=10, MDM=0, WAN=0, MODU=5 LANM=0 CkSRC=5 VMAIL=1(VER=3 TYP=1) 1-X=0 CALLS=2(TOT=180679) 16:35:36 2663163112mS H323Evt: Recv: RegistrationRequest 192.168.1.102; Extn(250), time since last RRQ-KA 55011, Endpoints registered: 13; Endpoints in registration: 0 16:35:41 2663168860mS SIP Rx: UDP 192.168.1.108:5060 -> 10.1.0.21:5060 OPTIONS sip:9892693555@192.168.1.108 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.108:5060;branch=z9hG4bKac1532345277 Max-Forwards: 70 From: ;tag=1c1532308513 To: Call-ID: 1532304603199201723550@192.168.1.108 CSeq: 1 OPTIONS Contact: Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE User-Agent: MP-124E FXS/v.6.60A.332.002 Accept: application/sdp, application/simple-message-summary, message/sipfrag Content-Length: 0 16:35:41 2663168865mS SIP Tx: UDP 10.1.0.21:5060 -> 192.168.1.108:5060 SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.1.108:5060;branch=z9hG4bKac1532345277 From: ;tag=1c1532308513 Call-ID: 1532304603199201723550@192.168.1.108 CSeq: 1 OPTIONS Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,INFO,REFER,NOTIFY,UPDATE Supported: timer Server: IP Office 9.1.6.0 build 153 To: ;tag=e4236d09165470a8 Content-Type: application/sdp Content-Length: 233 v=0 o=UserA 3332829689 1705415226 IN IP4 0.0.0.0 s=Session SDP c=IN IP4 0.0.0.0 t=0 0 m=audio 8000 RTP/AVP 0 8 18 4 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:4 G723/16000 16:35:42 2663169217mS RES: Mon 18/9/2017 16:35:42 FreeMem=47663664 Heap=45474844(1) Cache=2188820 MemObjs=33830(36418) CMMsg=8(9) ASN=0 Buff=5200 1359 1000 7363 5 Links=85097(85971) BTree=3347(6936) CPU=18.33% CPUStats=18.40%/5/10/144/12101/15010/00.13%/ 1/02.77% MCR=0 MCW=0 16:35:42 2663169217mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=52 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=95 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=50(TLS=5) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034 16:35:42 2663169217mS RES4: XML MemObjs=63 PoolMem=5796992(3) FreePoolMem=5781688(0) 16:35:42 2663169217mS RES5: CLog MemObjs=4866 FreePoolMem(Objs)=6968(134) TotalMem=704500 16:35:47 2663174219mS RES: Mon 18/9/2017 16:35:47 FreeMem=47708900 Heap=45507632(1) Cache=2201268 MemObjs=33694(36418) CMMsg=8(9) ASN=0 Buff=5200 1359 1000 7364 5 Links=85093(85971) BTree=3347(6936) CPU=18.01% CPUStats=17.23%/1/5/144/12203/15010/00.11%/1 /02.76% MCR=0 MCW=0 16:35:47 2663174219mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=52 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=93 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=50(TLS=5) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034 16:35:47 2663174219mS RES4: XML MemObjs=63 PoolMem=5796992(3) FreePoolMem=5781688(0) 16:35:47 2663174219mS RES5: CLog MemObjs=4866 FreePoolMem(Objs)=6968(134) TotalMem=704500 16:35:52 2663179232mS PRN: Optimizing BTree Lists Completed...Started:2663179231 Duration:1 Size:382 Attempted:382 16:36:00 2663187508mS CMExtnRx: v=474, p1=0 CMReleaseComp Line: type=DigitalExtn 9 Call: lid=0 id=660867 in=0 16:36:00 2663187509mS CMCallEvt: c0a8000a000a1583 0.660867.0 180676 wmaikrzek.0: StateChange: END=A CMCSConnected->CMCSCompleted 16:36:00 2663187510mS CMExtnEvt: v=22 State, new=PortRecoverDelay old=Connected,0,0,wmaikrzek 16:36:00 2663187511mS CMLOGGING: CALL:2017/09/1816:32,00:03:37,000,474,O,19895506799,519895506799,wmaikrzek,,,0,,"",0,n/a 16:36:00 2663187511mS CD: CALL: 0.660867.0 BState=Connected Cut=2 Music=0.0 Aend="wmaikrzek(474)" (11.24) Bend="Line 5" [Line 5] (3.24) CalledNum=19895506799 () CallingNum=474 (wmaikrzek) Internal=0 Time=229627 AState=Idle 16:36:00 2663187512mS CD: CALL: 0.660867.0 Deleted 16:36:00 2663187512mS CMExtnEvt: wmaikrzek: CALL LOST (CMCauseNormal) 16:36:00 2663187512mS CMExtnEvt: wmaikrzek: Extn(474) Calling Party Number(474) Type(CMNTypeInternal) 16:36:00 2663187512mS CMExtnEvt: wmaikrzek: CMExtnHandler::SetCurrent( id: 660867->0 ) 16:36:00 2663187513mS CMCallEvt: c0a8000a000a1583 0.660867.0 -1 wmaikrzek.-1: StateChange: END=X CMCSCompleted->CMCSDelete 16:36:00 2663187514mS CMLineTx: v=5 CMDisconnect Line: type=Q931Line 5 Call: lid=0 id=660871 in=0 Cause=16, Normal call clearing 16:36:00 2663187514mS CMCallEvt: c0a8000a000a1587 0.660871.0 -1 Q931 Trunk:5 CHAN=23: StateChange: END=X CMCSConnected->CMCSCompleted 16:36:00 2663187514mS CMCallEvt: END CALL:180676 (f4cf64d8) 16:36:00 2663187515mS CMCallEvt: c0a8000a000a1583 0.660867.0 -1 BaseEP: DELETE CMEndpoint f4832b2c TOTAL NOW=3 CALL_LIST=1 16:36:00 2663187518mS ISDNL3Evt: v=5 stacknum=5 State, new=DiscReq, old=Active id=660871 16:36:00 2663187518mS CMMap: PCG::UnmapBChan pcp[94]b1r0 cp_b f534dbc8 other_cp_b f497c9f8 16:36:00 2663187519mS CMMap: a=11.24 b=3.24 M02 16:36:00 2663187519mS CMMap: PCG::UnmapBChan pcp[236]b1r0 cp_b f497c9f8 other_cp_b 0 16:36:00 2663187520mS ISDNL3Evt: v=5 stacknum=5 State, new=ReleaseReq, old=DiscReq id=660871 16:36:00 2663187525mS ISDNL3Evt: v=5 stacknum=5 State, new=NullState, old=ReleaseReq id=660871 16:36:00 2663187526mS CMLineRx: v=5 CMReleaseComp Line: type=Q931Line 5 Call: lid=0 id=660871 in=0 16:36:00 2663187526mS CMCallEvt: c0a8000a000a1587 0.660871.0 -1 Q931 Trunk:5 CHAN=23: StateChange: END=X CMCSCompleted->CMCSDelete 16:36:00 2663187527mS CMTARGET: ISDN BChannel 23: in-service check = 1 16:36:00 2663187527mS CMTARGET: ISDN BChannel 23: in-service check = 1 16:36:00 2663187527mS CMCallEvt: c0a8000a000a1587 0.660871.0 -1 BaseEP: DELETE CMEndpoint f47a2d98 TOTAL NOW=2 CALL_LIST=1 16:36:00 2663187730mS RES: Mon 18/9/2017 16:36:01 FreeMem=47733024 Heap=45507632(1) Cache=2225392 MemObjs=33647(36418) CMMsg=8(9) ASN=0 Buff=5200 1359 1000 7363 5 Links=85080(85971) BTree=3343(6936) CPU=17.36% CPUStats=17.03%/1/5/144/12146/15010/00.12%/1 /02.78% MCR=0 MCW=0 16:36:00 2663187730mS RES2: IP 500 V2 9.1.6.0 build 153 Tasks=52 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=96 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=50(TLS=5) TAPI=0 Partner=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034 16:36:00 2663187730mS RES4: XML MemObjs=63 PoolMem=5796992(3) FreePoolMem=5781688(0) 16:36:00 2663187730mS RES5: CLog MemObjs=4866 FreePoolMem(Objs)=6968(134) TotalMem=704500 16:36:02 2663189513mS CMExtnEvt: wmaikrzek: Recover Timer reason=CMTRWrapUp 16:36:02 2663189513mS CMExtnEvt: v=22 State, new=Idle old=PortRecoverDelay,0,0,wmaikrzek 16:36:02 2663189514mS CMExtnTx: v=474, p1=0 CMVoiceMailStatus Line: type=DigitalExtn 9 Call: lid=0 id=-1 in=0 Called[wmaikrzek Msgs=0 Old=0 Sav=1] Type=Default (100) Reason=CMDRdirect Calling[00000000] Type=Default Plan=Default Display [wmaikrzek Msgs=0] Timed: 18/09/17 16:36 16:36:05 2663192531mS H323Evt: Recv: RegistrationRequest 192.168.1.103; Extn(251), time since last RRQ-KA 55011, Endpoints registered: 13; Endpoints in registration: 0 16:36:07 2663194135mS CMExtnEvt: kkociba: No user activity 16:36:10 2663197846mS H323Evt: Recv: RegistrationRequest 192.168.1.106; Extn(254), time since last RRQ-KA 55011, Endpoints registered: 13; Endpoints in registration: 0 16:36:13 2663200779mS H323Evt: Recv: RegistrationRequest 192.168.1.105; Extn(253), time since last RRQ-KA 55011, Endpoints registered: 13; Endpoints in registration: 0 16:36:21 2663208646mS H323Evt: Recv: RegistrationRequest 192.168.252.132; Extn(601), time since last RRQ-KA 55042, Endpoints registered: 13; Endpoints in registration: 0 16:36:21 2663208744mS H323Evt: Recv: RegistrationRequest 192.168.252.139; Extn(612), time since last RRQ-KA 55042, Endpoints registered: 13; Endpoints in registration: 0 16:36:22 2663209189mS H323Evt: Recv: RegistrationRequest 192.168.252.136; Extn(606), time since last RRQ-KA 55042, Endpoints registered: 13; Endpoints in registration: 0 16:36:22 2663209991mS H323Evt: Recv: RegistrationRequest 192.168.1.104; Extn(252), time since last RRQ-KA 55010, Endpoints registered: 13; Endpoints in registration: 0 16:36:23 2663210124mS H323Evt: Recv: RegistrationRequest 192.168.252.134; Extn(604), time since last RRQ-KA 55043, Endpoints registered: 13; Endpoints in registration: 0 16:36:25 2663212043mS H323Evt: Recv: RegistrationRequest 192.168.252.138; Extn(611), time since last RRQ-KA 55044, Endpoints registered: 13; Endpoints in registration: 0 ********** Warning: Logging to Screen Stopped **********