CVP Log: 25: 172.31.240.51: Feb 06 2008 16:09:25.555 +0100: %CVP_4_1_IVR-1-STATE_CHANGED_IN_SERVICE: IVR subsystem is IN SERVICE state. State: In Service. Cause: Dependency is at full service [id:3001] 28: 172.31.240.51: Feb 06 2008 16:16:23.608 +0100: %CVP_4_1_IVR-3-CALL_TIMED_OUT: Removing CALLGUID: 46CE973F-D3FD11DC-80490014-69730054 Timed out waiting for instructions from ICM Subsystem. (Client: 10.6.123.251, Timeout: 5s) HTTP req: { MSG_TYPE=CALL_RESULT, ERROR_CODE=NONE(0), CALL_ID=46CE973F-D3FD11DC-80490014-69730054, CALL_SEQ_NUM=2 } [id:3015] Console Log: 15:28:13 Initializing Event Management System (EMS) Library. 15:28:13 Trace: EMS Server pipe Customer\Voice Browser\VBEMSPipe enabled for Customer\Voice Browser\VB 15:28:13 Trace: Release 4.1.1, Build 1498 15:28:13 Trace: INFO: Registry base = CVP\Customer\Voice Browser 15:28:13 Trace: INFO: Process Name = VB 15:28:13 Trace: INFO: ICRRoot = C:\Cisco\CVP\bin 15:28:13 Initializing Node Manager Library. 15:28:13 Trace: INFO: Voice Browser Reading Registry... 15:28:13 Trace: Monitor Server pipe Customer\Voice Browser\VBCmdPipe enabled for Customer\Voice Browser\VB 15:28:13 Trace: Monitor Server pipe Customer\Voice Browser\VBReadOnlyCmdPipe enabled for Customer\Voice Browser\VBReadOnly 15:28:13 Trace: INFO: Voice Browser initializing globals... 15:28:13 Trace: INFO: VBRegistry::SetRegNotify Setting Registry trace 15:28:13 Trace: INFO: Voice Browser starting threads... 15:28:15 Trace: INFO: Resolving IP address for ING04CVPCALL01 15:28:17 Trace: INFO: IP address for ING04CVPCALL01 is 172.31.240.51 15:28:17 Trace: INFO: Gatekeeper configured is 172.31.240.97. Registration attempts will start with first GK in this list until a successful registration occurs 15:28:17 Trace: INFO: H323CallMgr::getRegistrySettings: maxCalls(defined in radvision config as Q931.maxCalls) = 1400 15:28:17 Trace: INFO: H323CallMgr::getRegistrySettings: maxIVRPorts = 50 15:28:17 Trace: INFO: H323CallMgr::getRegistrySettings: maxTotalCalls = 135 15:28:17 Trace: INFO: H323CallMgr::getRegistrySettings: takebackPercentage = 0 15:28:17 Trace: INFO: H323CallMgr::getRegistrySettings: startingRtpPort = 16384 15:28:17 Trace: INFO: H323CallMgr::getRegistrySettings: radConfigPath = C:\Cisco\CVP\VoiceBrowser\Config.val 15:28:17 Trace: INFO: H323CallMgr::getRegistrySettings: pktInterval = 20 15:28:17 Trace: INFO: H323CallMgr::getRegistrySettings: adminMode = 1 15:28:17 Trace: INFO: H323CallMgr::getRegistrySettings: RaiMaxThreshold = 80 15:28:17 Trace: INFO: H323CallMgr::getRegistrySettings: RaiMinThreshold = 70 15:28:17 Trace: INFO: H323CallMgr::getRegistrySettings: Codec = g711Ulaw64k 15:28:17 Trace: INFO: H323CallMgr::getRegistrySettings: CpuMaxThreshold = 99 15:28:17 Trace: INFO: H323CallMgr::getRegistrySettings: CpuMinThreshold = 94 15:28:17 Trace: INFO: H323CallMgr::getRegistrySettings: CpuHealthCheck = 0 15:28:17 Trace: INFO: H323CallMgr::getRegistrySettings: CpuSustainedTime = 15 15:28:17 Trace: INFO: H323CallMgr::getRegistrySettings: CpuOverloadReject = 0 15:28:17 Trace: INFO: H323CallMgr::getRegistrySettings: PerfmonIntervalTimer = 5000 15:28:17 Trace: INFO: H323CallMgr::getRegistrySettings: MemMaxThreshold = 80 15:28:17 Trace: INFO: H323CallMgr::getRegistrySettings: MemMinThreshold = 60 15:28:17 Trace: INFO: Voice Browser Main Thread Active... 15:28:17 Trace: INFO: H.225 Call signalling address of Voice Browser is 172.31.240.51:1720 15:28:17 Trace: INFO: Voice Browser Trace Mask is 0x101083 15:28:18 Trace: INFO: Starting HEALTH long poller to Call server localhost:8000/cvp/VBServlet 15:28:37 Trace: INFO: Initial registration with gatekeeper 15:28:37 Voice Browser communication to the Gatekeeper successful, alarm cleared. 15:28:37 Trace: SYSLOG: Server: STATUS=2, Port: 514 15:28:37 Trace: INFO: H323CallMgr::sendRAI: Successfully sent RAI for resource unavailability 15:28:39 Voice Browser can now access an Call Server, alarm cleared. 15:28:39 Voice Browser ING04CVPCALL01 is in service. 15:28:39 Trace: INFO: Ready to process calls 15:28:39 Trace: INFO: H323CallMgr::sendRAI: Successfully sent RAI for resource availability 15:28:39 Trace: INFO: Registry change event 15:28:39 Trace: INFO: Registry setting changed for OutOfServiceFlag from 1 to 0 15:28:39 Trace: INFO: VBRegistry::SetRegNotify Setting Registry trace 15:58:01 Trace: -------Voice Browser Interval Statistics------- 15:58:01 Trace: Calls: 15:58:01 Trace: Interval Statistics: 15:58:01 Trace: Interval size: 1800 15:58:01 Trace: New calls this interval: 0 15:58:01 Trace: Max call arrival per second: 0. 15:58:01 Trace: Calls transferred this interval: 0 15:58:01 Trace: Max IP Transfer per second: 0. 15:58:01 Trace: Calls redirected this interval: 0 15:58:01 Trace: Transfers not completed this interval: 0 15:58:01 Trace: Prompts not found this interval: 0 15:58:01 Trace: Calls using critical media: 0 15:58:01 Trace: Calls finished this interval: 0 15:58:01 Trace: Avg CPU Usage (percent): 8 15:58:01 Trace: Max CPU Usage (percent): 71 15:58:01 Trace: Min CPU Usage (percent): 0 15:58:01 Trace: Std Dev. CPU Usage(theta): 13 15:58:01 Trace: -------Voice Browser Snapshot Statistics------- 15:58:01 Trace: Snapshot Statistics: 15:58:01 Trace: Calls In Progress: 0 15:58:01 Trace: Calls Waiting for VXML: 0 15:58:01 Trace: Calls Playing Prompts: 0 15:58:01 Trace: IVR Ports in use: 0 15:58:01 Trace: Calls Waiting for DTMF: 0 15:58:01 Trace: Calls Transferring: 0 15:58:01 Trace: Calls Transferred: 0 15:58:01 Trace: Calls Disconnecting: 0 15:58:01 Trace: Calls Disconnected: 0 15:58:01 Trace: New calls: 0 15:58:01 Trace: Other: 0 15:58:01 Trace: Internal Call count: 0 15:58:01 Trace: System memory in use (percent): 46 15:58:01 Trace: -------Voice Browser Total Statistics----------- 15:58:01 Trace: Since Startup: 15:58:01 Trace: Total Calls: 0 15:58:01 Trace: Disconnect Disposition: 15:58:01 Trace: Redirected: 0 15:58:01 Trace: Caller Hangup: 0 15:58:01 Trace: Called Party Hangup: 0 15:58:01 Trace: ICM Release: 0 15:58:01 Trace: Critical Media: 0 15:58:01 Trace: Max Simultaneous Calls: 0 15:58:01 Trace: Max IVR Ports: 0 15:58:01 Trace: Total prompts not found: 0 15:58:01 Trace: Total transfers not completed: 0 15:58:01 Trace: Busy: 0 15:58:01 Trace: Ring-no-answer: 0 15:58:01 Trace: Gatekeeper problem: 0 15:58:01 Trace: Destination problem: 0 15:58:01 Trace: Other: 0 15:58:01 Trace: System Startup Time: Feb 06 2008, 15:28:17 15:58:01 Trace: System UpTime: 0 Days, 00 Hours, 29 Minutes, 44 Seconds 15:58:01 Trace: Current State: In Service 15:58:01 Trace: Packets Transmitted(approx): 0. 15:58:01 Trace: --------- Current Alarms --------- 15:58:01 Trace: None 16:01:32 Trace: INFO: LongPoll Failed -- Got OUT_OF_SERVICE from Call Server 16:01:32 Voice Browser to Call Server localhost:8000 connection unsuccessful. 16:01:32 Voice Browser cannot access any Call Servers and is no longer accepting calls. 16:01:32 Voice Browser ING04CVPCALL01 is out of service. 16:01:32 Trace: INFO: Registry change event 16:01:32 Trace: INFO: H323CallMgr::sendRAI: Successfully sent RAI for resource unavailability 16:01:32 Trace: INFO: Registry setting changed for OutOfServiceFlag from 0 to 1 16:01:32 Trace: INFO: VBRegistry::SetRegNotify Setting Registry trace 16:09:25 Voice Browser can now access an Call Server, alarm cleared. 16:09:25 Voice Browser ING04CVPCALL01 is in service. 16:09:25 Trace: INFO: Ready to process calls 16:09:25 Trace: INFO: Registry change event 16:09:25 Trace: INFO: H323CallMgr::sendRAI: Successfully sent RAI for resource availability 16:09:25 Voice Browser to Call Server localhost:8000 connection successful. 16:09:25 Trace: INFO: Registry setting changed for OutOfServiceFlag from 1 to 0 16:09:25 Trace: INFO: VBRegistry::SetRegNotify Setting Registry trace 16:15:40 Trace: Monitor connection established in Customer\Voice Browser\VB for user Administrator. 16:16:08 Trace: 00000001: CALLFLOW: New call: From IP address=10.126.31.123 ANI=002242939676 To DNIS=94498418850128900000, stackID=9460174 : DNIS = 94498418850128900000 : CID = 46CE973F-D3FD11DC-80490 014-69730054 16:16:08 Trace: 00000001: CALLFLOW: Call successfully established (slow start) : DNIS = 94498418850128900000 : CID = 46CE973F-D3FD11DC-80490014-69730054 16:16:08 Trace: 00000001: CALLFLOW: Initiating IP transfer to 2000944984188501111110000 : DNIS = 94498418850128900000 : CID = 46CE973F-D3FD11DC-80490014-69730054 16:16:08 Trace: 00000002: CALLFLOW: IP transfer in progress to 10.126.31.123 : DNIS = 2000944984188501111110000 : GUID = 531C717E-A502001F-2537A40D-C2D31009 : CID = 46CE973F-D3FD11DC-80490014-69730054 16:16:08 Trace: 00000002: CALLFLOW: IP transfer successfully established (slow start) : DNIS = 2000944984188501111110000 : GUID = 531C717E-A502001F-2537A40D-C2D31009 : CID = 46CE973F-D3FD11DC-80490014 -69730054 16:16:09 Trace: INFO: Starting ASYNC long poller to Call server http://172.31.240.51:8000/cvp/VBServlet 16:16:10 Trace: INFO: Starting ASYNC long poller to Call server http://172.31.240.51:8000/cvp/VBServlet 16:16:11 Trace: INFO: Starting ASYNC long poller to Call server http://172.31.240.51:8000/cvp/VBServlet 16:16:23 Trace: 00000002: INFO: cmHookRecv : IVR call leg had some abnormal failures : DNIS = 2000944984188501111110000 : GUID = 531C717E-A502001F-2537A40D-C2D31009 : CID = 46CE973F-D3FD11DC-80490014- 69730054 16:16:23 Trace: 00000002: INFO: CH323CallState::ReceivedOutRLC : Egress endpoint/gateway 10.126.31.123 had some unexpected reason for call disconnect : DNIS = 2000944984188501111110000 : GUID = 531C71 7E-A502001F-2537A40D-C2D31009 : CID = 46CE973F-D3FD11DC-80490014-69730054 16:16:23 Trace: 00000002: CALLFLOW: IP transfer - Agent hung up : DNIS = 2000944984188501111110000 : GUID = 531C717E-A502001F-2537A40D-C2D31009 : CID = 46CE973F-D3FD11DC-80490014-69730054 16:16:23 Trace: 00000002: CALLFLOW: Call ended : DNIS = 2000944984188501111110000 : GUID = 531C717E-A502001F-2537A40D-C2D31009 : CID = 46CE973F-D3FD11DC-80490014-69730054 16:16:25 Trace: 00000001: CALLFLOW: Disconnecting caller because agent hung up. : DNIS = 94498418850128900000 : CID = 46CE973F-D3FD11DC-80490014-69730054 16:16:26 Trace: 00000001: CALLFLOW: Disconnected forcefully : DNIS = 94498418850128900000 : CID = 46CE973F-D3FD11DC-80490014-69730054 16:16:26 Trace: 00000001: CALLFLOW: Call ended : DNIS = 94498418850128900000 : CID = 46CE973F-D3FD11DC-80490014-69730054