Friday, April 1, 2016

How to determine SFP module installed in Cisco Devices

Below There are some commands that will aide in determining what type of SFP is currently installed on your devices.



Cisco Router- example CISCO7204VXR

Show inventory raw


NAME: "module 0/1", DESCR: "1000BaseLX"
PID:                   , VID:    , SN:      






Cisco Switch- example 6500

Show inventory raw

NAME: "Chassis 1 Transceiver Te1/5/4", DESCR: "Chassis 1 X2 Transceiver 10Gbase-LX4 Te1/5/4"
PID: X2-10GB-LX4       ,                     VID: V04 , SN: XXXXXXX




Cisco Switch-  example Nexus 5K

Show interfaces capabilities 

Ethernet1/2
  Model:                 N5K-C5596UP-SUP
  Type (SFP capable):    1000base-SX
  Speed:                 1000,10000
  Duplex:                full
  Trunk encap. type:     802.1Q

Thursday, July 16, 2015

How to determine if DTMF Digits are being passed SIP using RTP-NTE

Call Flow Example: PSTN>>>CUBE>>>CVP>>>ICM

Example Scenerio : Customers call 800-555-1234, and press 9 to dial by extension  at IVR prompt and then press desired extension  78945.


You check the route call detail for the call and see that caller entered digits does not equal 78945. (7894 for example)

You check CVP logs and the caller entered digits the same as shown in ICM.

Next, you want to determine if CUBE is receiving the correct digits from the telco and if its forwarding the correct digits.


Use debug voip rtp session named-event on the CUBE to see the DTMF digits entered by the caller.


Example Output

40579832: .Jul 16 14:41:03.899:          s=VoIP d=DSP payload 0x64 ssrc 0xA8633D3B sequence 0x6057 timestamp 0xC371A6EC
40579833: .Jul 16 14:41:03.899:  <<<Rcv> Pt:100    Evt:8       Pkt:0A 00 00
40579834: .Jul 16 14:41:03.899:          s=DSP d=VoIP payload 0x64 ssrc 0xA8633D3B sequence 0x6057 timestamp 0xC371A6EC
40579835: .Jul 16 14:41:03.899:          Pt:100    Evt:8       Pkt:0A 00 00  <Snd>>>
40579836: .Jul 16 14:41:03.919:          s=VoIP d=DSP payload 0x64 ssrc 0xA8633D3B sequence 0x6059 timestamp 0xC371A6EC
40579837: .Jul 16 14:41:03.919:  <<<Rcv> Pt:100    Evt:8       Pkt:0A 00 A0
40579838: .Jul 16 14:41:03.919:          s=DSP d=VoIP payload 0x64 ssrc 0xA8633D3B sequence 0x6059 timestamp 0xC371A6EC
40579839: .Jul 16 14:41:03.919:          Pt:100    Evt:8       Pkt:0A 00 A0  <Snd>>>
40579840: .Jul 16 14:41:03.939:          s=VoIP d=DSP payload 0x64 ssrc 0xA8633D3B sequence 0x605B timestamp 0xC371A6EC
40579841: .Jul 16 14:41:03.939:  <<<Rcv> Pt:100    Evt:8       Pkt:0A 01 40
40579842: .Jul 16 14:41:03.939:          s=DSP d=VoIP payload 0x64 ssrc 0xA8633D3B sequence 0x605B timestamp 0xC371A6EC
40579843: .Jul 16 14:41:03.939:          Pt:100    Evt:8       Pkt:0A 01 40  <Snd>>>
40579844: .Jul 16 14:41:03.959:          s=VoIP d=DSP payload 0x64 ssrc 0xA8633D3B sequence 0x605D timestamp 0xC371A6EC
40579845: .Jul 16 14:41:03.959:  <<<Rcv> Pt:100    Evt:8       Pkt:0A 01 E0
40579846: .Jul 16 14:41:03.959:          s=DSP d=VoIP payload 0x64 ssrc 0xA8633D3B sequence 0x605D timestamp 0xC371A6EC
40579847: .Jul 16 14:41:03.959:          Pt:100    Evt:8       Pkt:0A 01 E0  <Snd>>>
40579848: .Jul 16 14:41:03.979:          s=VoIP d=DSP payload 0x64 ssrc 0xA8633D3B sequence 0x605F timestamp 0xC371A6EC
40579849: .Jul 16 14:41:03.979:  <<<Rcv> Pt:100    Evt:8       Pkt:0A 02 80
40579850: .Jul 16 14:41:03.979:          s=DSP d=VoIP payload 0x64 ssrc 0xA8633D3B sequence 0x605F timestamp 0xC371A6EC
40579851: .Jul 16 14:41:03.979:          Pt:100    Evt:8       Pkt:0A 02 80  <Snd>>>

Based on the output above 

EVT:8 would be the digit pressed by the caller.

SSRC = Synchronization source identifier uniquely identifies the source of a stream. Therefore , if customer dialed 8 to dial by extension then ext. 78945 all the digits pressed on this call would have the same SSRC ID.

<<<Rcv>/ <Snd>>> = Received and sent packets under normal behavior a packet that is received from one leg of the call is sent to the other leg of the call.


SequenceThe sequence number is incremented by one for each RTP data packet sent and is to be used by the receiver to detect packet loss and to restore packet sequence. 

Thursday, December 18, 2014

Traditional SRST Outbound CallerID Manipulation

 Scenario:

T1 PRI provider only allows outbound calls on their trunk from DID's assigned to the circuit. This would not be a noticeable problem when your enterprise endpoints are registered to CUCM and the proper external phone number masks are configured or when using CME SRST configuration where you can assign the external phone number masks to the enterprise phones. However, Traditional SRST does not provide the flexibility to configure this option and therefore digit manipulation needs to take place.

Example: 
You have DID range 212-555- 1100 to 212-555-1110. Your corresponding internal extensions 1100-1110.
In traditional SRST, the phones use the same configuration file they downloaded from CUCM when they register to their SRST reference gateway. Therefore their Calling party number will appear as their 4 digit DN in this case.

When the phone with extension 1100 attempts to make an outbound call via the PRI the provider will send the cause code below since they are expecting and will only allow calls from one of the assigned DID's/

Cause i = 0x82B9 - Bearer capability not presently authorized

The same error will be returned by the provider if an incoming call to 1100 is forwarded to external voicemail since the redirecting number  would be 1100.

Solution:

We need to use voice translation rules to resolve the issue.

voice translation-rule 5
rule 1 /^11\(..\)/ /21255511\1/

Matches number beginning with 11 and followed by any two digits. Prefixes 21255511 

voice translation-profile SRST_Outbound_CallerID
 translate calling 5

Creates a profile which applies translation-rule 5 to calling number

Dial-peer voice 100 pots
destination-pattern [2-9]..[2-9]...
translation-profile outgoing SRST_Outbound_CallerID

Applies translation profile in the outgoing direction to your matching outbound dial-peer


If your using an external number to forward calls to voicemail we need to translate the redirecting number as well.

example: 718-555-2222 calls 212-555-1100 while in Traditional SRST fallback mode. The call gets forwarded to an external number 646-555-5555 which routes the call to your Unity Connection server. Since the phone is configured with extension 1100 that would be the redirecting number sent to the PSTN. The call will be rejected by the carrier.

Solution:

voice translation-rule 6
rule 1 /^11\(..\)/ /21255511\1/
match your internal for digit extension and translate it to the 10 digit DID expected by the carrier

voice translation-profile SRST_Redirect_VM
 translate redirect-called 6
Create translation profile which will apply translation rule 6 to the redirecting number 

dial-peer voice 500 pots
destination-pattern 6465555555 
translation-profile outgoing SRST_Redirect_VM

Apply the profile to the matching outbound dial-peer of the external voice mail number

Note: Cisco documents that the translation profile can be applied under call-manager fallback but it did not work for me and I did not test it further. Also make sure you understand the effects of applying the profiles to the dial-peer since these are used in non SRST mode as well.




Tuesday, June 10, 2014

How to verify network disconnects from a Windows machine



EventViewer -> Application and Services -> Microsoft -> Windows -> Network Profile -> <right click> Operational -> Filter Current Log -> enter event ID 10001 -> click OK 

Here we should see all connect/disconnect events for the machine's interfaces.

Tuesday, February 18, 2014

Basic CTIOS Desktop log Analysis Example


 In this example agent logs in, goes ready, receives call, places call on hold , retrieves call and releases call.
 


01/21/14 13:25:33.165  CTIOSTrace - InitInstance(), Creating window for message processing...
01/21/14 13:25:33.172  CTIOSTrace - InitInstance(), Created window.
01/21/14 13:25:33.172  CTIOSTrace - InitInstance(), Starting message pump...
01/21/14 13:25:33.172  CTIOSTrace - CConnectionMonitor::MonitorThread()
01/21/14 13:25:33.172  CTIOSTrace - CConnectionMonitor::MonitorThread, Waiting on 0 Connections.
01/21/14 13:25:33.183  CTIOSTrace - CConnectionMonitor::AddClient(CTIOSSoftphone.exe_7464_6632).
01/21/14 13:25:33.183  CTIOSTrace - CConnectionMonitor::MonitorThread, Waiting for list to be modified
01/21/14 13:25:33.183  CTIOSTrace - CConnectionMonitor::AddClient, Adding Connection 0, (CTIOSSoftphone.exe_7464_6632)
01/21/14 13:25:33.183  CTIOSTrace - CConnectionMonitor::MonitorThread, Waiting on 1 Connections.
01/21/14 13:25:33.183  ********* Started logging facility for CTIOSSoftphone.exe_7464_6632 *********
01/21/14 13:25:33.184  7464  CTIOSSoftphone  Thd(4568)  LogWrapper::Start, ServerMonitorThread started successfully.
01/21/14 13:25:33.184  7464  CTIOSSoftphone  Thd(4568)  LogWrapper::Start, Debug Output is OFF.
01/21/14 13:25:33.184  7464  CTIOSSoftphone  Thd(4568)  LogWrapper::Start, Screen Output is ON.
01/21/14 13:25:33.184  7464  CTIOSSoftphone  Thd(4568)  LogWrapper::Start, WaitThread started successfully.
01/21/14 13:25:33.185  7464  CTIOSSoftphone  Thd(4568)  LogWrapper::Start, WaitCurUserThread started successfully.
01/21/14 13:25:33.256  CTIOSTrace - CConnectionMonitor::AddClient(CTIOSSoftphone.exe_7464_7240).
01/21/14 13:25:33.256  CTIOSTrace - CConnectionMonitor::AddClient, Adding Connection 1, (CTIOSSoftphone.exe_7464_7240)
01/21/14 13:25:33.256  CTIOSTrace - CConnectionMonitor::MonitorThread, Waiting for list to be modified
01/21/14 13:25:33.256  CTIOSTrace - CConnectionMonitor::MonitorThread, Waiting on 2 Connections.
01/21/14 13:25:33.257  ********* Started logging facility for CTIOSSoftphone.exe_7464_7240 *********
01/21/14 13:25:33.260  7464  CTIOSSoftphone  Thd(4568)  LogWrapper::Start, ServerMonitorThread started successfully.
01/21/14 13:25:33.261  7464  CTIOSSoftphone  Thd(4568)  LogWrapper::Start, Debug Output is OFF.
01/21/14 13:25:33.262  7464  CTIOSSoftphone  Thd(4568)  LogWrapper::Start, Screen Output is ON.
01/21/14 13:25:33.267  7464  CTIOSSoftphone  Thd(4568)  LogWrapper::Start, WaitThread started successfully.
01/21/14 13:25:33.268  7464  CTIOSSoftphone  Thd(4568)  LogWrapper::Start, WaitCurUserThread started successfully.
01/21/14 13:25:35.847  7464  CTIOSSoftphone  Thd(4568)  CCtiOsSession::SetSupervisorSilentMonitorMode
01/21/14 13:25:40.715  7464  CTIOSSoftphone  Thd(4568)  CCtiOsSession::Connect: Missing CTIOS_MAXHEARTBEATS keyword. Using default value [3]
01/21/14 13:25:40.733  7464  CTIOSSoftphone  Thd(4568)  CCtiOsObject(04A84DB0)::ReportError( Code(-100) )
(Agent desktop connects to CTIOS Server ‘s IP address and port number)
01/21/14 13:25:40.741  7464  CTIOSSoftphone  Thd(4568)  ** Attempting to connect to server [10.10.210.21 (10.10.210.21) port:42028] **
01/21/14 13:25:43.742  7464  CTIOSSoftphone  Thd(4568)  CNetPort(04ADCB40)::InitializeSecureSockets(), security path [C:\Program Files\Cisco Systems\CTIOS Client\CTIOS Security\]
01/21/14 13:25:43.742  7464  CTIOSSoftphone  Thd(4568)  CNetPort(04ADCB40)::InitializeSecureSockets(), HandshakeTime [5000]
01/21/14 13:25:45.212  7464  CTIOSSoftphone  Thd(4568)  CSSLCtx::ConfigCACert(), error:02001002:system library:fopen:No such file or directory
01/21/14 13:25:45.212  7464  CTIOSSoftphone  Thd(4568)  CSSLCtx(04AAB248)::ConfigCACert(), Error loading certificates locations
01/21/14 13:25:45.212  7464  CTIOSSoftphone  Thd(4568)  CSSLClient(04AAB248)::Init(), failed to configure CA certificate
01/21/14 13:25:45.212  7464  CTIOSSoftphone  Thd(4568)  CNetPort(04ADCB40)::OpenSecure, failed to create, set, and configure Context and SSL objects

( Connection  successful . CTIOS Server should show online in agent desktop status bar)
01/21/14 13:25:45.213  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eOnConnection ), EnablementMask = ffffffff
01/21/14 13:25:45.213  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (MsgID:eOnConnection EvtTime:24345213 CurSvr:10.10.210.21 CurPort:42028 SecConn:0)
01/21/14 13:25:45.214  7464  CTIOSSoftphone  Thd(4332)  NotifyConnectionRestored:: Adding system event eSysCTIOSServerOnline
01/21/14 13:25:45.247  7464  CTIOSSoftphone  Thd(4568)  CCtiOsObject(04A84DB0)::ReportError( Code(-100) )
01/21/14 13:25:45.247  7464  CTIOSSoftphone  Thd(4568)  CComCtiosObject::GetValueArray. No value associated with property -> Login
01/21/14 13:25:45.249  7464  CTIOSSoftphone  Thd(4568)  CCtiOsSession::MakeRequest(eGlobalSettingsDownloadRequest)
01/21/14 13:25:45.249  7464  CTIOSSoftphone  Thd(4568)  CCtiOsSession::MakeRequest: (DsktpTyp:0)
01/21/14 13:25:45.250  7464  CTIOSSoftphone  Thd(4568)  CCtiOsObject(04A84DB0)::ReportError( Code(-100) )
01/21/14 13:25:45.250  7464  CTIOSSoftphone  Thd(4568)  CComCtiosObject::GetValueArray. No value associated with property -> Login
01/21/14 13:25:45.253  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eGlobalSettingsDownloadConf ), EnablementMask = ffffffff
(Agent desktop downloading its settings )
01/21/14 13:25:45.254  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (MsgID:eGlobalSettingsDownloadConf DsktpSetngs:(ScrnPref:(MainScreen:(AgentStatisticsIntervalSec:15 BringToFrontOnCall:1 FlashOnCall:0 RecordingEnabled:0) TeamRealTime:(ColumnAutoResize:0)) Grid:(SGStats:(Col:(1:(Typ:SkillGroupNumber Hdr:SkillGroupNumber) 10:(Typ:AgentsTalkingOther Hdr:AgentsTalkingOther) 11:(Typ:AgentsHold Hdr:AgentsHold) 12:(Typ:AgentsReserved Hdr:AgentsReserved) 13:(Typ:AgentsBusyOther Hdr:AgentsBusyOther) 14:(Typ:AgentsWorkNotReady Hdr:AgentsWorkNotReady) 15:(Typ:AgentsWorkReady Hdr:AgentsWorkReady) 16:(Typ:HandledCallsToday Hdr:HandledCallsToday) 17:(Typ:HandledCallsTalkTimeToday Hdr:HandledCallsTalkTimeToday) 2:(Typ:SkillGroupName Hdr:SkillGroupName) 3:(Typ:RouterCallsQNow Hdr:RouterCallsQNow) 4:(Typ:LongestRouterCallQNow Hdr:LongestRouterCallQNow) 5:(Typ:AgentsLoggedOn Hdr:AgentsLoggedOn) 6:(Typ:AgentsNotReady Hdr:AgentsNotReady) 7:(Typ:AgentsReady Hdr:AgentsReady) 8:(Typ:AgentsTalkingIn Hdr:AgentsTalkingIn) 9:(Typ:AgentsTalkingOut Hdr:AgentsTalkingOut))) AGStats:(Col:(1:(Typ:CallsHandledToday Hdr:CallsHandledToday) 2:(Typ:HandledCallsTimeToday Hdr:HandledCallsTimeToday) 3:(Typ:TimeTalkingToday Hdr:TimeTalkingToday) 4:(Typ:TimeHoldingToday Hdr:TimeHoldingToday) 5:(Typ:TimeReadyToday Hdr:TimeReadyToday) 6:(Typ:TimeNotReadyToday Hdr:TimeNotReadyToday)))CallAppearance:(Col:(1:(Typ:CallID Hdr:CallID) 10:(Typ:Var2 Hdr:Var2editable:true maxchars:40) 11:(Typ:Var3 Hdr:Var3editable:true maxchars:40) 12:(Typ:Var4 Hdr:Var4editable:true maxchars:40) 13:(Typ:Var5 Hdr:Var5editable:true maxchars:40) 14:(Typ:Var6 Hdr:Var6editable:true maxchars:40) 15:(Typ:Var7 Hdr:Var7editable:true maxchars:40) 16:(Typ:Var8 Hdr:Var8editable:true maxchars:40) 17:(Typ:Var9 Hdr:Var9editable:true maxchars:40) 18:(Typ:Var10 Hdr:Var10editable:true maxchars:40) 2:(Typ:CallStatus Hdr:CallStatus) 3:(Typ:CallType Hdr:CallType) 4:(Typ:DNIS Hdr:DNIS) 5:(Typ:ANI Hdr:ANI) 6:(Typ:CED Hdr:CED) 7:(Typ:DialedNumber Hdr:DialedNumber) 8:(Typ:Wrapup Hdr:Wrapupeditable:true maxchars:39) 9:(Typ:Var1 Hdr:Var1editable:true maxchars:40)))) Login:(ConnProfs:(UCCE:(PrphID:5000 CtiOsA:sprawler CtiOsB:sprawler PortA:42028 PortB:42028 HB:5 MaxHBs:3 AutoLogin:1 WarnIfAlrdyLogdIn:0 ShowFldBitMsk:163 RejIfAlrdyLogdIn:0 IPCCSMEnbl:0 TOS:104 RasCallMode:0SwitchCapabilityBitMask:2134842367 WarnIfSilentMonitored:0)))IPCCSilentMonitor:(Settings:(HBIntv:5 MediaTermPort:4000 TOS:184 MonIPPort:39200 HBTmout:15CCMBasedSilentMonitor:0)) SoundPreferences:(DTMF:(Mute:0) DialTone:(Mute:0) OrgTone:(Mute:1) RngInTone:(Mute:1) All:(Mute:0)) Version:()) CILConnID:21)
01/21/14 13:25:45.254  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnGlobalSettingsDownloadConf()
01/21/14 13:25:45.255  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::DeskSetting(ScreenPreferences) (MainScreen:(AgentStatisticsIntervalSec:15 BringToFrontOnCall:1 FlashOnCall:0 RecordingEnabled:0) TeamRealTime:(ColumnAutoResize:0))
01/21/14 13:25:45.255  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::DeskSetting(Grid) (SGStats:(Col:(1:(Typ:SkillGroupNumber Hdr:SkillGroupNumber) 10:(Typ:AgentsTalkingOther Hdr:AgentsTalkingOther) 11:(Typ:AgentsHold Hdr:AgentsHold) 12:(Typ:AgentsReserved Hdr:AgentsReserved) 13:(Typ:AgentsBusyOther Hdr:AgentsBusyOther) 14:(Typ:AgentsWorkNotReady Hdr:AgentsWorkNotReady) 15:(Typ:AgentsWorkReady Hdr:AgentsWorkReady) 16:(Typ:HandledCallsToday Hdr:HandledCallsToday) 17:(Typ:HandledCallsTalkTimeToday Hdr:HandledCallsTalkTimeToday) 2:(Typ:SkillGroupName Hdr:SkillGroupName) 3:(Typ:RouterCallsQNow Hdr:RouterCallsQNow) 4:(Typ:LongestRouterCallQNow Hdr:LongestRouterCallQNow) 5:(Typ:AgentsLoggedOn Hdr:AgentsLoggedOn) 6:(Typ:AgentsNotReady Hdr:AgentsNotReady) 7:(Typ:AgentsReady Hdr:AgentsReady) 8:(Typ:AgentsTalkingIn Hdr:AgentsTalkingIn) 9:(Typ:AgentsTalkingOut Hdr:AgentsTalkingOut))) AGStats:(Col:(1:(Typ:CallsHandledToday Hdr:CallsHandledToday) 2:(Typ:HandledCallsTimeToday Hdr:HandledCallsTimeToday) 3:(Typ:TimeTalkingToday Hdr:TimeTalkingToday) 4:(Typ:TimeHoldingToday Hdr:TimeHoldingToday) 5:(Typ:TimeReadyToday Hdr:TimeReadyToday) 6:(Typ:TimeNotReadyToday Hdr:TimeNotReadyToday)))CallAppearance:(Col:(1:(Typ:CallID Hdr:CallID) 10:(Typ:Var2 Hdr:Var2editable:true maxchars:40) 11:(Typ:Var3 Hdr:Var3editable:true maxchars:40) 12:(Typ:Var4 Hdr:Var4editable:true maxchars:40) 13:(Typ:Var5 Hdr:Var5editable:true maxchars:40) 14:(Typ:Var6 Hdr:Var6editable:true maxchars:40) 15:(Typ:Var7 Hdr:Var7editable:true maxchars:40) 16:(Typ:Var8 Hdr:Var8editable:true maxchars:40) 17:(Typ:Var9 Hdr:Var9editable:true maxchars:40) 18:(Typ:Var10 Hdr:Var10editable:true maxchars:40) 2:(Typ:CallStatus Hdr:CallStatus) 3:(Typ:CallType Hdr:CallType) 4:(Typ:DNIS Hdr:DNIS) 5:(Typ:ANI Hdr:ANI) 6:(Typ:CED Hdr:CED) 7:(Typ:DialedNumber Hdr:DialedNumber) 8:(Typ:Wrapup Hdr:Wrapupeditable:true maxchars:39) 9:(Typ:Var1 Hdr:Var1editable:true maxchars:40))))
01/21/14 13:25:45.256  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::DeskSetting(Login) (ConnProfs:(UCCE:(PrphID:5000 CtiOsA:sprawler CtiOsB:sprawler PortA:42028 PortB:42028 HB:5 MaxHBs:3 AutoLogin:1 WarnIfAlrdyLogdIn:0 ShowFldBitMsk:163 RejIfAlrdyLogdIn:0 IPCCSMEnbl:0 TOS:104 RasCallMode:0SwitchCapabilityBitMask:2134842367 WarnIfSilentMonitored:0)))
01/21/14 13:25:45.256  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::DeskSetting(IPCCSilentMonitor) (Settings:(HBIntv:5 MediaTermPort:4000 TOS:184 MonIPPort:39200 HBTmout:15CCMBasedSilentMonitor:0))
01/21/14 13:25:45.256  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::DeskSetting(SoundPreferences) (DTMF:(Mute:0) DialTone:(Mute:0) OrgTone:(Mute:1) RngInTone:(Mute:1) All:(Mute:0))
01/21/14 13:25:45.256  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::DeskSetting(Version) ()
(I  closed the agent desktop.)
01/21/14 13:25:45.578  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eOnConnectionClosed ), EnablementMask = ffffffff
01/21/14 13:25:45.578  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (MsgID:eOnConnectionClosed)
01/21/14 13:25:45.578  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnConnectionClosed()
-------------------------------------------------------------------------------------------------------------------------------------------------
( I reopened the agent desktop)
01/21/14 13:26:02.421  CTIOSTrace - CConnectionMonitor::AddClient(CTIOSSoftphone.exe_7464_4960).
01/21/14 13:26:02.421  CTIOSTrace - CConnectionMonitor::MonitorThread, Waiting for list to be modified
01/21/14 13:26:02.421  CTIOSTrace - CConnectionMonitor::AddClient, Adding Connection 2, (CTIOSSoftphone.exe_7464_4960)
01/21/14 13:26:02.421  CTIOSTrace - CConnectionMonitor::MonitorThread, Waiting on 3 Connections.
01/21/14 13:26:02.421  ********* Started logging facility for CTIOSSoftphone.exe_7464_4960 *********
01/21/14 13:26:02.421  7464  CTIOSSoftphone  Thd(4568)  LogWrapper::Start, ServerMonitorThread started successfully.
01/21/14 13:26:02.421  7464  CTIOSSoftphone  Thd(4568)  LogWrapper::Start, Debug Output is OFF.
01/21/14 13:26:02.421  7464  CTIOSSoftphone  Thd(4568)  LogWrapper::Start, Screen Output is ON.
01/21/14 13:26:02.422  7464  CTIOSSoftphone  Thd(4568)  LogWrapper::Start, WaitThread started successfully.
01/21/14 13:26:02.422  7464  CTIOSSoftphone  Thd(4568)  LogWrapper::Start, WaitCurUserThread started successfully.
01/21/14 13:26:08.015  7464  CTIOSSoftphone  Thd(4568)  CSSLClient(04AAB248)::SaveClientCacheSession(), SSL object is NULL
01/21/14 13:26:08.019  7464  CTIOSSoftphone  Thd(4568)  Attempting to resolve hostname [sprawler] to IP address (gethostbyname).
( reconnecting to CTIOS Server)
01/21/14 13:26:08.039  7464  CTIOSSoftphone  Thd(4568)  ** Attempting to connect to server [sprawler (10.10.210.21) port:42028] **
01/21/14 13:26:08.041  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eOnConnection ), EnablementMask = ffffffff
01/21/14 13:26:08.041  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (MsgID:eOnConnection EvtTime:24368041 CurSvr:sprawler CurPort:42028 SecConn:0)
01/21/14 13:26:08.041  7464  CTIOSSoftphone  Thd(4332)  NotifyConnectionRestored:: Adding system event eSysCTIOSServerOnline
01/21/14 13:26:08.046  7464  CTIOSSoftphone  Thd(4568)  CCtiOsSession::MakeRequest(eIdentifyClientRequest)
01/21/14 13:26:08.046  7464  CTIOSSoftphone  Thd(4568)  CCtiOsSession::MakeRequest: (ClntPwd:(null) CILClntID:elvinmorales-PC-7464-4332)
01/21/14 13:26:08.047  7464  CTIOSSoftphone  Thd(4568)  CCtiOsSession::MakeRequest(eSetSessionModeRequest)
( Initial agent state is unknown)
01/21/14 13:26:08.047  7464  CTIOSSoftphone  Thd(4568)  CCtiOsSession::MakeRequest: (PrphID:5000 PrphTyp:0 AGState:eUnknown AvailTimeTdy:0 LogdOnTimeTdy:0 NotRdyTimeTdy:0 AGOutCallsTdy:0 AGOutCallsTlkTimeTdy:0 AGOutCallsTimeTdy:0 AGOutCallsHldTdy:0 AGOutCallsHldTimeTdy:0 HdlCallsTdy:0 HdlCallsTlkTimeTdy:0 HdlCallsTimeTdy:0 IncCallsHldTdy:0 IncCallsHldTimeTdy:0 IntCallsHldTdy:0 IntCallsHldTimeTdy:0 AvailTimeSess:0 LogdOnTimeSess:0 NotRdyTimeSess:0 AGOutCallsSess:0 AGOutCallsTlkTimeSess:0 AGOutCallsTimeSess:0 AGOutCallsHldSess:0 AGOutCallsHldTimeSess:0 HdlCallsSess:0 HdlCallsTlkTimeSess:0 HdlCallsTimeSess:0 IncCallsHldSess:0 IncCallsHldTimeSess:0 IntCallsSess:0 IntCallsTimeSess:0 IntCallsRcvdTimeSess:0 IntCallsHldSess:0 IntCallsHldTimeSess:0 IntCallsTdy:0 IntCallsTimeTdy:0 HdlCallsAftCallTimeSess:0 HdlCallsAftCallTimeTdy:0 MRDID:0 ICMAGID:0 AGMode:2 MaxTaskLim:0 NumTasks:0 AGExt:(null) AGID:9111 AGInstr:5002 SGs:() UniqObjID:(null) IntCallsRcvdTdy:0 IntCallsRcvdTimeTdy:0 IntCallsRcvdSess:0 ClntAGTempID:agent.1390332362 ClassId:1 IsSupv:0 LstErr:(4568:1) ConnMode:1 AutoLogin:1 SavAGState:9 WaitforRecvry:0 SavLoginInfo:() CurProf:UCCE LoginTime:0 IsAGTeamMbr:0 AGAvailStatus:-1 ICMAvailTimeSess:0 RoutblTimeTdy:0 ICMAvailTimeTdy:0 RoutblTimeSess:0 LoginNam:(null) AGCallMode:0 SMTgtAGUID:(null) SMCallUID:(null))

(
01/21/14 13:26:08.048  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eIdentifyClientConf ), EnablementMask = ffffffff
01/21/14 13:26:08.048  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (ClntPwd:(null) ClntAddr:10.10.100.254 MsgID:eIdentifyClientConf CILClntID:elvinmorales-PC-7464-4332 ProdVer:7.1 SMMode:1)
01/21/14 13:26:08.048  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnIdentifyClientConf()
01/21/14 13:26:08.051  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eSetAgentModeEvent ), EnablementMask = ffffffff
01/21/14 13:26:08.051  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (PrphID:5000 PrphTyp:0 AGState:eUnknown AvailTimeTdy:0 LogdOnTimeTdy:0 NotRdyTimeTdy:0 AGOutCallsTdy:0 AGOutCallsTlkTimeTdy:0 AGOutCallsTimeTdy:0 AGOutCallsHldTdy:0 AGOutCallsHldTimeTdy:0 HdlCallsTdy:0 HdlCallsTlkTimeTdy:0 HdlCallsTimeTdy:0 IncCallsHldTdy:0 IncCallsHldTimeTdy:0 IntCallsHldTdy:0 IntCallsHldTimeTdy:0 AvailTimeSess:0 LogdOnTimeSess:0 NotRdyTimeSess:0 AGOutCallsSess:0 AGOutCallsTlkTimeSess:0 AGOutCallsTimeSess:0 AGOutCallsHldSess:0 AGOutCallsHldTimeSess:0 HdlCallsSess:0 HdlCallsTlkTimeSess:0 HdlCallsTimeSess:0 IncCallsHldSess:0 IncCallsHldTimeSess:0 IntCallsSess:0 IntCallsTimeSess:0 IntCallsRcvdTimeSess:0 IntCallsHldSess:0 IntCallsHldTimeSess:0 IntCallsTdy:0 IntCallsTimeTdy:0 HdlCallsAftCallTimeSess:0 HdlCallsAftCallTimeTdy:0 MRDID:0 ICMAGID:0 AGMode:2 MaxTaskLim:0 NumTasks:0 AGExt:(null) AGID:9111 AGInstr:5002 SGs:() UniqObjID:agent.5000.9111 MsgID:eSetAgentModeEvent IntCallsRcvdTdy:0 IntCallsRcvdTimeTdy:0 IntCallsRcvdSess:0 ClntAGTempID:agent.1390332362 ClassId:1 IsSupv:0 LstErr:(4568:1) ConnMode:1 Filt:filtertarget = agent.5000.9111 CILConnID:22 AutoLogin:1 SavAGState:9 WaitforRecvry:0 SavLoginInfo:() StatusSys:(StatusCTISvr:1 StatusCtiSvrDvr:1 StatusCC:1 StatusPrphs:(5000:1)) CurProf:UCCE LoginTime:0 IsAGTeamMbr:0 AGAvailStatus:-1 ICMAvailTimeSess:0 RoutblTimeTdy:0 ICMAvailTimeTdy:0 RoutblTimeSess:0 OrgClntID:elvinmorales-PC-7464-4332 LoginNam:(null) BlkAllEvts:1 AGCallMode:0 SMTgtAGUID:(null) SMCallUID:(null))
( Agent state identified as logged out)
01/21/14 13:26:08.052  7464  CTIOSSoftphone  Thd(4332)  [agent.5000.9111] eSetAgentModeEvent
01/21/14 13:26:08.056  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eQueryAgentStateConf ), EnablementMask = 1000000
01/21/14 13:26:08.056  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (PrphID:5000 AGState:eLogout NumSGs:3 MRDID:1 ICMAGID:5003 AGMode:0 MaxTaskLim:0 NumTasks:0 AGExt:5002 AGID:9111 AGInstr:5002 Msk:0x1000000 UniqObjID:agent.5000.9111 MsgID:eQueryAgentStateConf IncWrpupStr:(string0:Insert incoming wrapup string 0 here. string1:Insert incoming wrapup string 1 here. string2:Insert incoming wrapup string 2 here. string3:Insert incoming wrapup string 3 here.) NotRdyRsnCodes:(Insert not ready reason code 1 here.:1 Insert not ready reason code 2 here.:2 Insert not ready reason code 3 here.:3 Insert not ready reason code 4 here.:4) LogoutRsnCodes:(Insert logout reason code 1 here.:1 Insert logout reason code 2 here.:2 Insert logout reason code 3 here.:3 Insert logout reason code 4 here.:4) NotRdyRsnReq:0 LogoutRsnReq:0 AGAvailStatus:0SkillGroup[1]:(SG#:25849 SGID:5000 SGPri:0 SGState:1) SkillGroup[2]:(SG#:1 SGID:5001 SGPri:0 SGState:1) SkillGroup[3]:(SG#:0 SGID:5002 SGPri:0 SGState:1))
01/21/14 13:26:08.057  7464  CTIOSSoftphone  Thd(4332)  [agent.5000.9111]::OnQueryAgentStateConf()
( Agent logs in successfully, login information displayed)
01/21/14 13:26:08.058  7464  CTIOSSoftphone  Thd(4568)  [agent.5000.9111]::Login()
01/21/14 13:26:08.058  7464  CTIOSSoftphone  Thd(4568)  [agent.5000.9111]::SetAgentState()
01/21/14 13:26:08.058  7464  CTIOSSoftphone  Thd(4568)  [agent.5000.9111]::MakeRequest( eSetAgentStateRequest )
01/21/14 13:26:08.058  7464  CTIOSSoftphone  Thd(4568)  [agent.5000.9111]::MakeRequest: (PrphID:5000 AGState:eLogin AGWorkMode:0 AGExt:5002 AGID:9111 AGInstr:5002 AGPwd:cisco123 UniqObjID:agent.5000.9111 ClntAGTempID:agent.1390332362 ClassId:1 RmtLogin:0)
01/21/14 13:26:08.058  7464  CTIOSSoftphone  Thd(4568)  CCtiOsSession::MakeRequest(eSetAgentStateRequest)
01/21/14 13:26:08.058  7464  CTIOSSoftphone  Thd(4568)  CCtiOsSession::MakeRequest: (PrphID:5000 AGState:eLogin AGWorkMode:0 AGExt:5002 AGID:9111 AGInstr:5002 AGPwd:cisco123 UniqObjID:agent.5000.9111 ClntAGTempID:agent.1390332362 ClassId:1 RmtLogin:0)
01/21/14 13:26:08.060  7464  CTIOSSoftphone  Thd(4332)  ObjectId = agent.5000.9111 , Enablement Mask = 1000000
01/21/14 13:26:08.086  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eAgentInfoEvent ), EnablementMask = ffffffff
01/21/14 13:26:08.086  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (AGID:9111 AGLstNam:morales AGFstNam:elvin UniqObjID:agent.5000.9111 MsgID:eAgentInfoEvent SupvKey:(null) LoginNam:student1)
01/21/14 13:26:08.086  7464  CTIOSSoftphone  Thd(4332)  [agent.5000.9111] eAgentInfoEvent
01/21/14 13:26:08.357  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eSkillInfoEvent ), EnablementMask = ffffffff
01/21/14 13:26:08.357  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (SG#:25849 UniqObjID:skillgroup.5000.25849 MsgID:eSkillInfoEvent SGNam:000637976542)
01/21/14 13:26:08.361  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eSkillInfoEvent ), EnablementMask = ffffffff
01/21/14 13:26:08.361  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (SG#:25849 UniqObjID:skillgroup.5000.25849 MsgID:eSkillInfoEvent SGNam:000637976542)
01/21/14 13:26:08.362  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eSkillInfoEvent ), EnablementMask = ffffffff
01/21/14 13:26:08.362  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (SG#:0 UniqObjID:skillgroup.5000.0 MsgID:eSkillInfoEvent SGNam:support.sg)
01/21/14 13:26:08.366  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eSkillInfoEvent ), EnablementMask = ffffffff
01/21/14 13:26:08.366  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (SG#:0 UniqObjID:skillgroup.5000.0 MsgID:eSkillInfoEvent SGNam:support.sg)
( Agent state changed to default Not Ready)
01/21/14 13:26:08.367  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eAgentStateEvent ), EnablementMask = a1b0010
01/21/14 13:26:08.368  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (PrphID:5000 PrphTyp:17 AGState:eNotReady SG#:25849 SGID:5000 StateDur:0 SGPri:0 EvtRsnCode:0 SGState:0 SessID:0 MRDID:1 ICMAGID:5003 AGMode:1 MaxTaskLim:1 NumTasks:0 AGExt:5002 AGID:9111 AGInstr:5002 CTIClntSig:(null) Msk:0xa1b0010 UniqObjID:agent.5000.9111 MsgID:eAgentStateEvent DvrKey:agent.5000.9111 IncOrOut:21327 WrpupOKEnbl:1 AGAvailStatus:0)
01/21/14 13:26:08.368  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, Event(eAgentStateEvent) is blocked.

(Agent Skillgroup information identified)
01/21/14 13:26:08.368  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eSkillInfoEvent ), EnablementMask = ffffffff
01/21/14 13:26:08.368  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (SG#:1 UniqObjID:skillgroup.5000.1 MsgID:eSkillInfoEvent SGNam:sales.sg)
01/21/14 13:26:08.371  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eSkillInfoEvent ), EnablementMask = ffffffff
01/21/14 13:26:08.371  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (SG#:1 UniqObjID:skillgroup.5000.1 MsgID:eSkillInfoEvent SGNam:sales.sg)
01/21/14 13:26:08.372  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eSkillInfoEvent ), EnablementMask = ffffffff
01/21/14 13:26:08.372  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (SG#:0 UniqObjID:skillgroup.5000.0 MsgID:eSkillInfoEvent SGNam:support.sg)
01/21/14 13:26:08.374  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eSkillInfoEvent ), EnablementMask = ffffffff
01/21/14 13:26:08.374  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (SG#:0 UniqObjID:skillgroup.5000.0 MsgID:eSkillInfoEvent SGNam:support.sg)
01/21/14 13:26:08.375  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eAgentStateEvent ), EnablementMask = ffffffff
01/21/14 13:26:08.375  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (PrphID:5000 PrphTyp:17 AGState:eNotReady SG#:1 SGID:5001 StateDur:0 SGPri:0 EvtRsnCode:0 SGState:0 SessID:0 MRDID:1 ICMAGID:5003 AGMode:1 MaxTaskLim:1 NumTasks:0 AGExt:5002 AGID:9111 AGInstr:5002 CTIClntSig:(null) UniqObjID:agent.5000.9111 MsgID:eAgentStateEvent DvrKey:agent.5000.9111 AGAvailStatus:0)
01/21/14 13:26:08.375  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, Event(eAgentStateEvent) is blocked.
01/21/14 13:26:08.375  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eAgentStateEvent ), EnablementMask = ffffffff
01/21/14 13:26:08.375  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (PrphID:5000 PrphTyp:17 AGState:eNotReady SG#:25849 SGID:5000 StateDur:0 SGPri:0 EvtRsnCode:0 SGState:2 SessID:0 MRDID:1 ICMAGID:5003 AGMode:1 MaxTaskLim:1 NumTasks:0 AGExt:5002 AGID:9111 AGInstr:5002 CTIClntSig:(null) UniqObjID:agent.5000.9111 MsgID:eAgentStateEvent DvrKey:agent.5000.9111 AGAvailStatus:0)
01/21/14 13:26:08.376  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, Event(eAgentStateEvent) is blocked.
01/21/14 13:26:08.376  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eSetAgentStateConf ), EnablementMask = ffffffff
01/21/14 13:26:08.376  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (UniqObjID:agent.5000.9111 MsgID:eSetAgentStateConf FiltTgt:agent.5000.9111 TgtCILClntID:elvinmorales-PC-7464-4332 BlkAllEvts:0)
01/21/14 13:26:08.377  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eQueryAgentStateConf ), EnablementMask = a1b0010
01/21/14 13:26:08.378  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (PrphID:5000 AGState:eNotReady NumSGs:3 MRDID:1 ICMAGID:5003 AGMode:1 MaxTaskLim:1 NumTasks:0 AGExt:5002 AGID:9111 AGInstr:5002 Msk:0xa1b0010 UniqObjID:agent.5000.9111 MsgID:eQueryAgentStateConf IncWrpupStr:(string0:Insert incoming wrapup string 0 here. string1:Insert incoming wrapup string 1 here. string2:Insert incoming wrapup string 2 here. string3:Insert incoming wrapup string 3 here.) NotRdyRsnCodes:(Insert not ready reason code 1 here.:1 Insert not ready reason code 2 here.:2 Insert not ready reason code 3 here.:3 Insert not ready reason code 4 here.:4) LogoutRsnCodes:(Insert logout reason code 1 here.:1 Insert logout reason code 2 here.:2 Insert logout reason code 3 here.:3 Insert logout reason code 4 here.:4) NotRdyRsnReq:0 LogoutRsnReq:0 AGAvailStatus:0SkillGroup[1]:(SG#:25849 SGID:5000 SGPri:0 SGState:2) SkillGroup[2]:(SG#:1 SGID:5001 SGPri:0 SGState:2) SkillGroup[3]:(SG#:0 SGID:5002 SGPri:0 SGState:1))
01/21/14 13:26:08.379  7464  CTIOSSoftphone  Thd(4332)  [agent.5000.9111]::OnQueryAgentStateConf()
01/21/14 13:26:08.379  7464  CTIOSSoftphone  Thd(4568)  [agent.5000.9111]::MakeRequest( eEnableSkillGroupStatisticsRequest )
01/21/14 13:26:08.379  7464  CTIOSSoftphone  Thd(4568)  [agent.5000.9111]::MakeRequest: (UniqObjID:agent.5000.9111 ClassId:1)
01/21/14 13:26:08.379  7464  CTIOSSoftphone  Thd(4568)  CCtiOsSession::MakeRequest(eEnableSkillGroupStatisticsRequest)
01/21/14 13:26:08.379  7464  CTIOSSoftphone  Thd(4568)  CCtiOsSession::MakeRequest: (UniqObjID:agent.5000.9111 ClassId:1)
01/21/14 13:26:08.380  7464  CTIOSSoftphone  Thd(4568)  [agent.5000.9111]::MakeRequest( eEnableAgentStatisticsRequest )
01/21/14 13:26:08.380  7464  CTIOSSoftphone  Thd(4568)  [agent.5000.9111]::MakeRequest: (UniqObjID:agent.5000.9111 ClassId:1)
01/21/14 13:26:08.380  7464  CTIOSSoftphone  Thd(4568)  CCtiOsSession::MakeRequest(eEnableAgentStatisticsRequest)
01/21/14 13:26:08.380  7464  CTIOSSoftphone  Thd(4568)  CCtiOsSession::MakeRequest: (UniqObjID:agent.5000.9111 ClassId:1)
01/21/14 13:26:08.389  7464  CTIOSSoftphone  Thd(4568)  [agent.5000.9111]::MakeRequest( eEnableSkillGroupStatisticsRequest )
01/21/14 13:26:08.389  7464  CTIOSSoftphone  Thd(4568)  [agent.5000.9111]::MakeRequest: (UniqObjID:agent.5000.9111 ClassId:1)
01/21/14 13:26:08.389  7464  CTIOSSoftphone  Thd(4568)  CCtiOsSession::MakeRequest(eEnableSkillGroupStatisticsRequest)
01/21/14 13:26:08.389  7464  CTIOSSoftphone  Thd(4568)  CCtiOsSession::MakeRequest: (UniqObjID:agent.5000.9111 ClassId:1)
01/21/14 13:26:08.390  7464  CTIOSSoftphone  Thd(4568)  [agent.5000.9111]::MakeRequest( eEnableAgentStatisticsRequest )
01/21/14 13:26:08.390  7464  CTIOSSoftphone  Thd(4568)  [agent.5000.9111]::MakeRequest: (UniqObjID:agent.5000.9111 ClassId:1)
01/21/14 13:26:08.390  7464  CTIOSSoftphone  Thd(4568)  CCtiOsSession::MakeRequest(eEnableAgentStatisticsRequest)
01/21/14 13:26:08.390  7464  CTIOSSoftphone  Thd(4568)  CCtiOsSession::MakeRequest: (UniqObjID:agent.5000.9111 ClassId:1)
01/21/14 13:26:08.391  7464  CTIOSSoftphone  Thd(4332)  ObjectId = agent.5000.9111 , Enablement Mask = a1b0010
01/21/14 13:26:08.397  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eAgentDeskSettingsConf ), EnablementMask = a1b0010
01/21/14 13:26:08.397  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (PrphID:5000 DeskSetngsMsk:512 WrpupDataIncMode:1 WrpupDataOutMode:1 LogoutNonActvTime:4294967295 QualRecRate:4294967295 RngNoAnsTime:4294967295 WorkModeTimer:7200 RngNoAnsDN:0 SMWarnMsg:0 SMAudInd:0 SupvAssistCallMthd:0 EmerCallMthd:0 AutoRecOnEmer:0 RecMode:0 AGID:9111 DefDevPortAddr:(null) Msk:0xa1b0010 UniqObjID:agent.5000.9111 MsgID:eAgentDeskSettingsConf NotRdyRsnReq:0 LogoutRsnReq:0)
01/21/14 13:26:08.399  7464  CTIOSSoftphone  Thd(4332)  ObjectId = agent.5000.9111 , Enablement Mask = a1b0010
01/21/14 13:26:08.401  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eSkillInfoEvent ), EnablementMask = ffffffff
01/21/14 13:26:08.402  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (SG#:25849 UniqObjID:skillgroup.5000.25849 MsgID:eSkillInfoEvent SGNam:000637976542)
01/21/14 13:26:08.403  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eSkillInfoEvent ), EnablementMask = ffffffff
01/21/14 13:26:08.403  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (SG#:25849 UniqObjID:skillgroup.5000.25849 MsgID:eSkillInfoEvent SGNam:000637976542)
01/21/14 13:26:08.404  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eSkillInfoEvent ), EnablementMask = ffffffff
01/21/14 13:26:08.404  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (SG#:1 UniqObjID:skillgroup.5000.1 MsgID:eSkillInfoEvent SGNam:sales.sg)
01/21/14 13:26:08.405  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eSkillInfoEvent ), EnablementMask = ffffffff
01/21/14 13:26:08.405  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (SG#:1 UniqObjID:skillgroup.5000.1 MsgID:eSkillInfoEvent SGNam:sales.sg)
01/21/14 13:26:08.405  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eSkillInfoEvent ), EnablementMask = ffffffff
01/21/14 13:26:08.405  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (SG#:25849 UniqObjID:skillgroup.5000.25849 MsgID:eSkillInfoEvent SGNam:000637976542)
01/21/14 13:26:08.406  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eSkillInfoEvent ), EnablementMask = ffffffff
01/21/14 13:26:08.406  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (SG#:25849 UniqObjID:skillgroup.5000.25849 MsgID:eSkillInfoEvent SGNam:000637976542)
01/21/14 13:26:08.407  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eSkillInfoEvent ), EnablementMask = ffffffff
01/21/14 13:26:08.407  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (SG#:1 UniqObjID:skillgroup.5000.1 MsgID:eSkillInfoEvent SGNam:sales.sg)
01/21/14 13:26:08.408  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eSkillInfoEvent ), EnablementMask = ffffffff
01/21/14 13:26:08.408  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (SG#:1 UniqObjID:skillgroup.5000.1 MsgID:eSkillInfoEvent SGNam:sales.sg)
01/21/14 13:26:10.613  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eSnapshotDeviceConf ), EnablementMask = ffffffff
01/21/14 13:26:10.614  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (NumCalls:0 UniqObjID:device.5000.5002 MsgID:eSnapshotDeviceConf VldCalls:() NumSMTgtCalls:0)
01/21/14 13:26:10.614  7464  CTIOSSoftphone  Thd(4332)  [device.5000.5002] eSnapshotDeviceConf (NumCalls = 0)
(Agent goes ready and agent state changes to available)
01/21/14 13:26:17.396  7464  CTIOSSoftphone  Thd(4568)  [agent.5000.9111]::SetAgentState()
01/21/14 13:26:17.396  7464  CTIOSSoftphone  Thd(4568)  [agent.5000.9111]::MakeRequest( eSetAgentStateRequest )
01/21/14 13:26:17.396  7464  CTIOSSoftphone  Thd(4568)  [agent.5000.9111]::MakeRequest: (AGState:eAvailable EvtRsnCode:0 UniqObjID:agent.5000.9111 ClassId:1)
01/21/14 13:26:17.397  7464  CTIOSSoftphone  Thd(4568)  CCtiOsSession::MakeRequest(eSetAgentStateRequest)
01/21/14 13:26:17.397  7464  CTIOSSoftphone  Thd(4568)  CCtiOsSession::MakeRequest: (AGState:eAvailable EvtRsnCode:0 UniqObjID:agent.5000.9111 ClassId:1)
01/21/14 13:26:17.400  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eAgentStateEvent ), EnablementMask = 101b0000
01/21/14 13:26:17.400  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (PrphID:5000 PrphTyp:17 AGState:eAvailable SG#:25849 SGID:5000 StateDur:0 SGPri:0 EvtRsnCode:0 SGState:3 SessID:0 MRDID:1 ICMAGID:5003 AGMode:1 MaxTaskLim:1 NumTasks:0 AGExt:5002 AGID:9111 AGInstr:5002 CTIClntSig:CTIOSServer Msk:0x101b0000 UniqObjID:agent.5000.9111 MsgID:eAgentStateEvent DvrKey:agent.5000.9111 IncOrOut:21327 WrpupOKEnbl:1 AGAvailStatus:1)
01/21/14 13:26:17.401  7464  CTIOSSoftphone  Thd(4332)  [agent.5000.9111] eAgentStateEvent( eAvailable )
01/21/14 13:26:17.411  7464  CTIOSSoftphone  Thd(4332)  ObjectId = agent.5000.9111 , Enablement Mask = 101b0000
01/21/14 13:26:17.415  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eSetAgentStateConf ), EnablementMask = ffffffff
01/21/14 13:26:17.415  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (UniqObjID:agent.5000.9111 MsgID:eSetAgentStateConf FiltTgt:agent.5000.9111 TgtCILClntID:elvinmorales-PC-7464-4332 BlkAllEvts:0)
(Agent is placed in reserved state)
01/21/14 13:26:43.165  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eAgentStateEvent ), EnablementMask = ffffffff
01/21/14 13:26:43.165  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (PrphID:5000 PrphTyp:17 AGState:eReserved SG#:25849 SGID:5000 StateDur:0 SGPri:0 EvtRsnCode:0 SGState:7 SessID:0 MRDID:1 ICMAGID:5003 AGMode:1 MaxTaskLim:1 NumTasks:1 AGExt:5002 AGID:9111 AGInstr:5002 CTIClntSig:CTIOSServer UniqObjID:agent.5000.9111 MsgID:eAgentStateEvent DvrKey:agent.5000.9111 IncOrOut:21327 WrpupOKEnbl:1 AGAvailStatus:0)
01/21/14 13:26:43.165  7464  CTIOSSoftphone  Thd(4332)  [agent.5000.9111] eAgentStateEvent( eReserved )
( Pre call event observed. Data displays incoming call information)
01/21/14 13:26:43.174  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eAgentPrecallEvent ), EnablementMask = ffffffff
01/21/14 13:26:43.174  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (SVC#:4294967295 SVCID:4294967295 SG#:1 SGID:5001 SGPri:0 MonID:0 NumNamVars:8 NumNamArrs:0 MRDID:1 AGInstr:5002 ANI:3945001 UsrToUsrInfo:(null) Dialed#:1015 CallrEntrDig:1 RCallKeyDay:150783 RCallKeyCID:101 MsgID:eAgentPrecallEvent ecc:(...) ICMEntUniqID:icm.150783.101 RCallKeySeq#:1 CallTypIDTag:5001 PreCallIIDTag:124)
(Call begin event observed)
01/21/14 13:26:43.881  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eCallBeginEvent ), EnablementMask = ffffffff
01/21/14 13:26:43.882  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (PrphID:5000 PrphTyp:17 ConnCID:16782414 CallTyp:2 SVC#:4294967295 SVCID:4294967295 SGID:5001 SGPri:0 NumNamVars:8 NumNamArrs:0 ANI:3945001 DNIS:5002 Dialed#:1015 CallrEntrDig:1 RCallKeyDay:150783 RCallKeyCID:101 DevID:5002 UniqObjID:call.5000.16782414.5002  MsgID:eCallBeginEvent ecc:(...) ICMEntUniqID:icm.150783.101 DevUniqObjID:device.5000.5002 RCallKeySeq#:2)
01/21/14 13:26:43.885  7464  CTIOSSoftphone  Thd(4332)  [call.5000.16782414.5002] eCallBeginEvent

( call is delivered to the agent)
01/21/14 13:26:44.235  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eCallDeliveredEvent ), EnablementMask = 683f0001
01/21/14 13:26:44.236  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (CallTyp:2 SVC#:4294967295 SVCID:4294967295 EvtCause:65535 SG#:1 SGID:5001 LineTyp:0 SGPri:0 AlrtgDevID:5002 CallngDevID:3945001 CalldDevID:5002 Msk:0x683f0001 UniqObjID:call.5000.16782414.5002  MsgID:eCallDeliveredEvent ICMEntUniqID:icm.150783.101 DevUniqObjID:device.5000.5002)
01/21/14 13:26:44.236  7464  CTIOSSoftphone  Thd(4332)  [call.5000.16782414.5002] eCallDeliveredEvent
01/21/14 13:26:44.250  7464  CTIOSSoftphone  Thd(4332)  ObjectId = call.5000.16782414.5002 , Enablement Mask = 683f0001
(Agent Answers the call)
01/21/14 13:26:51.957  7464  CTIOSSoftphone  Thd(4568)  [call.5000.16782414.5002] eAnswerCallRequest
01/21/14 13:26:51.957  7464  CTIOSSoftphone  Thd(4568)  [call.5000.16782414.5002] eAnswerCallRequest
01/21/14 13:26:51.957  7464  CTIOSSoftphone  Thd(4568)  [call.5000.16782414.5002]::MakeRequest( eAnswerCallRequest )
01/21/14 13:26:51.957  7464  CTIOSSoftphone  Thd(4568)  [call.5000.16782414.5002]::MakeRequest: (UniqObjID:call.5000.16782414.5002 ClassId:3)
01/21/14 13:26:51.957  7464  CTIOSSoftphone  Thd(4568)  CCtiOsSession::MakeRequest(eAnswerCallRequest)
01/21/14 13:26:51.958  7464  CTIOSSoftphone  Thd(4568)  CCtiOsSession::MakeRequest: (UniqObjID:call.5000.16782414.5002 ClassId:3)
( Call answered confirmation event observed)
01/21/14 13:26:52.014  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eAnswerCallConf ), EnablementMask = 683f0000
01/21/14 13:26:52.014  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (CallTyp:2 Msk:0x683f0000 UniqObjID:call.5000.16782414.5002  MsgID:eAnswerCallConf ICMEntUniqID:icm.150783.101 DevUniqObjID:device.5000.5002)
01/21/14 13:26:52.016  7464  CTIOSSoftphone  Thd(4332)  ObjectId = call.5000.16782414.5002 , Enablement Mask = 683f0000
01/21/14 13:26:52.021  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eAgentStateEvent ), EnablementMask = ffffffff
(Agent is transitioned to a talking state)
01/21/14 13:26:52.021  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (PrphID:5000 PrphTyp:17 AGState:eTalking SG#:1 SGID:5001 StateDur:0 SGPri:0 EvtRsnCode:0 SGState:4 SessID:0 MRDID:1 ICMAGID:5003 AGMode:1 MaxTaskLim:1 NumTasks:1 AGExt:5002 AGID:9111 AGInstr:5002 CTIClntSig:CTIOSServer UniqObjID:agent.5000.9111 MsgID:eAgentStateEvent DvrKey:agent.5000.9111 IncOrOut:21327 WrpupOKEnbl:1 AGAvailStatus:0)
01/21/14 13:26:52.022  7464  CTIOSSoftphone  Thd(4332)  [agent.5000.9111] eAgentStateEvent( eTalking )
01/21/14 13:26:52.031  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eCallDataUpdateEvent ), EnablementMask = 683f0000
01/21/14 13:26:52.031  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (PrphID:5000 PrphTyp:17 ConnCID:16782414 CallTyp:2 SVC#:4294967295 SVCID:4294967295 SGID:5001 SGPri:0 NumNamVars:8 NumNamArrs:0 CmpgnID:4294967295 QryRuleID:4294967295 ANI:3945001 DNIS:5002 Dialed#:1015 CallrEntrDig:1 RCallKeyDay:150783 RCallKeyCID:101 Msk:0x683f0000 DevID:5002 UniqObjID:call.5000.16782414.5002  MsgID:eCallDataUpdateEvent ecc:(...) CTIClnts:(CTIClient[1]:(CTIClntSig:CTIOSServer CTIClntTmstmp:1383274511)) ICMEntUniqID:icm.150783.101 DevUniqObjID:device.5000.5002 RCallKeySeq#:2)
01/21/14 13:26:52.031  7464  CTIOSSoftphone  Thd(4332)  [call.5000.16782414.5002] eCallDataUpdateEvent
01/21/14 13:26:52.051  7464  CTIOSSoftphone  Thd(4332)  ObjectId = call.5000.16782414.5002 , Enablement Mask = 683f0000

(call established event observed)
01/21/14 13:26:52.054  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eCallEstablishedEvent ), EnablementMask = 68bf01a6
01/21/14 13:26:52.054  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (CallTyp:2 SVC#:4294967295 SVCID:4294967295 EvtCause:65535 SG#:1 SGID:5001 LineTyp:0 SGPri:0 CallngDevID:3945001 CalldDevID:5002 AnsDevID:5002 Msk:0x68bf01a6 UniqObjID:call.5000.16782414.5002  MsgID:eCallEstablishedEvent ICMEntUniqID:icm.150783.101 DevUniqObjID:device.5000.5002)
01/21/14 13:26:52.054  7464  CTIOSSoftphone  Thd(4332)  [call.5000.16782414.5002] eCallEstablishedEvent
01/21/14 13:26:52.069  7464  CTIOSSoftphone  Thd(4332)  ObjectId = call.5000.16782414.5002 , Enablement Mask = 68bf01a6
(The beginning of RTP packet transmission)
01/21/14 13:26:52.116  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eRTPStartedEvent ), EnablementMask = ffffffff
01/21/14 13:26:52.116  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (PrphID:5000 ConnCID:16782414 CallTyp:2 ConnDevIDTyp:0 MonID:0 ClntPort:24480 Dir:1 RTPTyp:0 BitRate:0 EchoCncl:1 PktSize:20 PyldTyp:4 AGExt:5002 AGID:9111 AGInstr:5002 ConnDevID:5002 ClntAddr:10.10.200.253 UniqObjID:call.5000.16782414.5002 MsgID:eRTPStartedEvent DvrKey:call.5000.16782414 ICMEntUniqID:icm.150783.101 DevUniqObjID:device.5000.5002)
01/21/14 13:26:52.117  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eRTPStartedEvent ), EnablementMask = ffffffff
01/21/14 13:26:52.117  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (PrphID:5000 ConnCID:16782414 CallTyp:2 ConnDevIDTyp:0 MonID:0 ClntPort:22406 Dir:0 RTPTyp:0 BitRate:1 EchoCncl:1 PktSize:20 PyldTyp:4 AGExt:5002 AGID:9111 AGInstr:5002 ConnDevID:5002 ClntAddr:10.10.100.254 UniqObjID:call.5000.16782414.5002 MsgID:eRTPStartedEvent DvrKey:call.5000.16782414 ICMEntUniqID:icm.150783.101 DevUniqObjID:device.5000.5002)
(Agent places call onhold)
01/21/14 13:27:03.892  7464  CTIOSSoftphone  Thd(4568)  [call.5000.16782414.5002] eHoldCallRequest
01/21/14 13:27:03.892  7464  CTIOSSoftphone  Thd(4568)  [call.5000.16782414.5002] eHoldCallRequest
01/21/14 13:27:03.893  7464  CTIOSSoftphone  Thd(4568)  [call.5000.16782414.5002]::MakeRequest( eHoldCallRequest )
01/21/14 13:27:03.893  7464  CTIOSSoftphone  Thd(4568)  [call.5000.16782414.5002]::MakeRequest: (UniqObjID:call.5000.16782414.5002 ClassId:3)
01/21/14 13:27:03.893  7464  CTIOSSoftphone  Thd(4568)  CCtiOsSession::MakeRequest(eHoldCallRequest)
01/21/14 13:27:03.893  7464  CTIOSSoftphone  Thd(4568)  CCtiOsSession::MakeRequest: (UniqObjID:call.5000.16782414.5002 ClassId:3)

(RTP packet transmission stop due to call placed on hold)
01/21/14 13:27:04.015  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eRTPStoppedEvent ), EnablementMask = ffffffff
01/21/14 13:27:04.015  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (PrphID:5000 ConnCID:16782414 CallTyp:2 ConnDevIDTyp:0 MonID:0 ClntPort:22406 Dir:0 AGExt:5002 AGID:9111 AGInstr:5002 ConnDevID:5002 ClntAddr:10.10.100.254 UniqObjID:call.5000.16782414.5002 MsgID:eRTPStoppedEvent DvrKey:call.5000.16782414 ICMEntUniqID:icm.150783.101 DevUniqObjID:device.5000.5002)
01/21/14 13:27:04.017  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eRTPStoppedEvent ), EnablementMask = ffffffff
01/21/14 13:27:04.018  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (PrphID:5000 ConnCID:16782414 CallTyp:2 ConnDevIDTyp:0 MonID:0 ClntPort:24480 Dir:1 AGExt:5002 AGID:9111 AGInstr:5002 ConnDevID:5002 ClntAddr:10.10.200.253 UniqObjID:call.5000.16782414.5002 MsgID:eRTPStoppedEvent DvrKey:call.5000.16782414 ICMEntUniqID:icm.150783.101 DevUniqObjID:device.5000.5002)
( call on hold confirmation)
01/21/14 13:27:04.049  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eHoldCallConf ), EnablementMask = 68bf01a2
01/21/14 13:27:04.050  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (CallTyp:2 Msk:0x68bf01a2 UniqObjID:call.5000.16782414.5002  MsgID:eHoldCallConf ICMEntUniqID:icm.150783.101 DevUniqObjID:device.5000.5002)
01/21/14 13:27:04.051  7464  CTIOSSoftphone  Thd(4332)  ObjectId = call.5000.16782414.5002 , Enablement Mask = 68bf01a2
01/21/14 13:27:04.053  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eAgentStateEvent ), EnablementMask = ffffffff
(Agent state changes due to call on hold)
01/21/14 13:27:04.054  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (PrphID:5000 PrphTyp:17 AGState:eHold SG#:1 SGID:5001 StateDur:0 SGPri:0 EvtRsnCode:0 SGState:10 SessID:0 MRDID:1 ICMAGID:5003 AGMode:1 MaxTaskLim:1 NumTasks:1 AGExt:5002 AGID:9111 AGInstr:5002 CTIClntSig:CTIOSServer UniqObjID:agent.5000.9111 MsgID:eAgentStateEvent DvrKey:agent.5000.9111 IncOrOut:21327 WrpupOKEnbl:1 AGAvailStatus:0)
01/21/14 13:27:04.054  7464  CTIOSSoftphone  Thd(4332)  [agent.5000.9111] eAgentStateEvent( eHold )
01/21/14 13:27:04.059  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eCallHeldEvent ), EnablementMask = 68bf000a
01/21/14 13:27:04.059  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (CallTyp:2 EvtCause:65535 HldgDevID:5002 Msk:0x68bf000a UniqObjID:call.5000.16782414.5002  MsgID:eCallHeldEvent ICMEntUniqID:icm.150783.101 DevUniqObjID:device.5000.5002)
01/21/14 13:27:04.059  7464  CTIOSSoftphone  Thd(4332)  [call.5000.16782414.5002] eCallHeldEvent
01/21/14 13:27:04.076  7464  CTIOSSoftphone  Thd(4332)  ObjectId = call.5000.16782414.5002 , Enablement Mask = 68bf000a
(Agent retrieves call from hold)
01/21/14 13:27:12.393  7464  CTIOSSoftphone  Thd(4568)  [call.5000.16782414.5002] eRetrieveCallRequest
01/21/14 13:27:12.393  7464  CTIOSSoftphone  Thd(4568)  [call.5000.16782414.5002] eRetrieveCallRequest
01/21/14 13:27:12.393  7464  CTIOSSoftphone  Thd(4568)  [call.5000.16782414.5002]::MakeRequest( eRetrieveCallRequest )
01/21/14 13:27:12.393  7464  CTIOSSoftphone  Thd(4568)  [call.5000.16782414.5002]::MakeRequest: (UniqObjID:call.5000.16782414.5002 ClassId:3)
01/21/14 13:27:12.394  7464  CTIOSSoftphone  Thd(4568)  CCtiOsSession::MakeRequest(eRetrieveCallRequest)
01/21/14 13:27:12.394  7464  CTIOSSoftphone  Thd(4568)  CCtiOsSession::MakeRequest: (UniqObjID:call.5000.16782414.5002 ClassId:3)
01/21/14 13:27:12.472  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eRetrieveCallConf ), EnablementMask = 68bf0002
01/21/14 13:27:12.473  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (CallTyp:2 Msk:0x68bf0002 UniqObjID:call.5000.16782414.5002  MsgID:eRetrieveCallConf ICMEntUniqID:icm.150783.101 DevUniqObjID:device.5000.5002)
01/21/14 13:27:12.474  7464  CTIOSSoftphone  Thd(4332)  ObjectId = call.5000.16782414.5002 , Enablement Mask = 68bf0002
01/21/14 13:27:12.476  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eAgentStateEvent ), EnablementMask = ffffffff

(Agent state changes back to talking)
01/21/14 13:27:12.476  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (PrphID:5000 PrphTyp:17 AGState:eTalking SG#:1 SGID:5001 StateDur:0 SGPri:0 EvtRsnCode:0 SGState:4 SessID:0 MRDID:1 ICMAGID:5003 AGMode:1 MaxTaskLim:1 NumTasks:1 AGExt:5002 AGID:9111 AGInstr:5002 CTIClntSig:CTIOSServer UniqObjID:agent.5000.9111 MsgID:eAgentStateEvent DvrKey:agent.5000.9111 IncOrOut:21327 WrpupOKEnbl:1 AGAvailStatus:0)
01/21/14 13:27:12.476  7464  CTIOSSoftphone  Thd(4332)  [agent.5000.9111] eAgentStateEvent( eTalking )
01/21/14 13:27:12.480  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eCallRetrievedEvent ), EnablementMask = 68bf01a6
01/21/14 13:27:12.480  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (CallTyp:2 EvtCause:65535 RetrvDevID:5002 Msk:0x68bf01a6 UniqObjID:call.5000.16782414.5002  MsgID:eCallRetrievedEvent ICMEntUniqID:icm.150783.101 DevUniqObjID:device.5000.5002)
01/21/14 13:27:12.480  7464  CTIOSSoftphone  Thd(4332)  [call.5000.16782414.5002] eCallRetrievedEvent
01/21/14 13:27:12.503  7464  CTIOSSoftphone  Thd(4332)  ObjectId = call.5000.16782414.5002 , Enablement Mask = 68bf01a6

( RTP packet transmission resumes)
01/21/14 13:27:12.507  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eRTPStartedEvent ), EnablementMask = ffffffff
01/21/14 13:27:12.508  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (PrphID:5000 ConnCID:16782414 CallTyp:2 ConnDevIDTyp:0 MonID:0 ClntPort:22406 Dir:0 RTPTyp:0 BitRate:1 EchoCncl:1 PktSize:20 PyldTyp:4 AGExt:5002 AGID:9111 AGInstr:5002 ConnDevID:5002 ClntAddr:10.10.100.254 UniqObjID:call.5000.16782414.5002 MsgID:eRTPStartedEvent DvrKey:call.5000.16782414 ICMEntUniqID:icm.150783.101 DevUniqObjID:device.5000.5002)
01/21/14 13:27:12.601  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eRTPStoppedEvent ), EnablementMask = ffffffff
01/21/14 13:27:12.601  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (PrphID:5000 ConnCID:16782414 CallTyp:2 ConnDevIDTyp:0 MonID:0 ClntPort:22406 Dir:0 AGExt:5002 AGID:9111 AGInstr:5002 ConnDevID:5002 ClntAddr:10.10.100.254 UniqObjID:call.5000.16782414.5002 MsgID:eRTPStoppedEvent DvrKey:call.5000.16782414 ICMEntUniqID:icm.150783.101 DevUniqObjID:device.5000.5002)
01/21/14 13:27:12.603  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eRTPStartedEvent ), EnablementMask = ffffffff
01/21/14 13:27:12.603  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (PrphID:5000 ConnCID:16782414 CallTyp:2 ConnDevIDTyp:0 MonID:0 ClntPort:29274 Dir:1 RTPTyp:0 BitRate:0 EchoCncl:1 PktSize:20 PyldTyp:4 AGExt:5002 AGID:9111 AGInstr:5002 ConnDevID:5002 ClntAddr:10.10.200.253 UniqObjID:call.5000.16782414.5002 MsgID:eRTPStartedEvent DvrKey:call.5000.16782414 ICMEntUniqID:icm.150783.101 DevUniqObjID:device.5000.5002)
01/21/14 13:27:12.603  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eRTPStartedEvent ), EnablementMask = ffffffff
01/21/14 13:27:12.603  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (PrphID:5000 ConnCID:16782414 CallTyp:2 ConnDevIDTyp:0 MonID:0 ClntPort:22406 Dir:0 RTPTyp:0 BitRate:1 EchoCncl:1 PktSize:20 PyldTyp:4 AGExt:5002 AGID:9111 AGInstr:5002 ConnDevID:5002 ClntAddr:10.10.100.254 UniqObjID:call.5000.16782414.5002 MsgID:eRTPStartedEvent DvrKey:call.5000.16782414 ICMEntUniqID:icm.150783.101 DevUniqObjID:device.5000.5002)

( Agent releases call, clear connection request observed)
01/21/14 13:27:30.516  7464  CTIOSSoftphone  Thd(4568)  [call.5000.16782414.5002] eClearConnectionRequest
01/21/14 13:27:30.516  7464  CTIOSSoftphone  Thd(4568)  [call.5000.16782414.5002] eClearConnectionRequest
01/21/14 13:27:30.516  7464  CTIOSSoftphone  Thd(4568)  [call.5000.16782414.5002]::MakeRequest( eClearConnectionRequest )
01/21/14 13:27:30.516  7464  CTIOSSoftphone  Thd(4568)  [call.5000.16782414.5002]::MakeRequest: (UniqObjID:call.5000.16782414.5002 ClassId:3)
01/21/14 13:27:30.516  7464  CTIOSSoftphone  Thd(4568)  CCtiOsSession::MakeRequest(eClearConnectionRequest)
01/21/14 13:27:30.517  7464  CTIOSSoftphone  Thd(4568)  CCtiOsSession::MakeRequest: (UniqObjID:call.5000.16782414.5002 ClassId:3)

(RTP transmission stop event)
01/21/14 13:27:31.629  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eRTPStoppedEvent ), EnablementMask = ffffffff
01/21/14 13:27:31.629  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (PrphID:5000 ConnCID:16782414 CallTyp:2 ConnDevIDTyp:0 MonID:0 ClntPort:22406 Dir:0 AGExt:5002 AGID:9111 AGInstr:5002 ConnDevID:5002 ClntAddr:10.10.100.254 UniqObjID:call.5000.16782414.5002 MsgID:eRTPStoppedEvent DvrKey:call.5000.16782414 ICMEntUniqID:icm.150783.101 DevUniqObjID:device.5000.5002)
01/21/14 13:27:31.630  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eRTPStoppedEvent ), EnablementMask = ffffffff
01/21/14 13:27:31.631  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (PrphID:5000 ConnCID:16782414 CallTyp:2 ConnDevIDTyp:0 MonID:0 ClntPort:29274 Dir:1 AGExt:5002 AGID:9111 AGInstr:5002 ConnDevID:5002 ClntAddr:10.10.200.253 UniqObjID:call.5000.16782414.5002 MsgID:eRTPStoppedEvent DvrKey:call.5000.16782414 ICMEntUniqID:icm.150783.101 DevUniqObjID:device.5000.5002)

( Call connection is being cleared)
01/21/14 13:27:31.635  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eCallConnectionClearedEvent ), EnablementMask = 3f0000
01/21/14 13:27:31.635  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (CallTyp:2 EvtCause:65535 RelDevID:5002 Msk:0x3f0000 UniqObjID:call.5000.16782414.5002  MsgID:eCallConnectionClearedEvent ICMEntUniqID:icm.150783.101 DevUniqObjID:device.5000.5002)
01/21/14 13:27:31.635  7464  CTIOSSoftphone  Thd(4332)  [call.5000.16782414.5002] eCallConnectionClearedEvent
01/21/14 13:27:31.663  7464  CTIOSSoftphone  Thd(4332)  ObjectId = call.5000.16782414.5002 , Enablement Mask = 3f0000
01/21/14 13:27:31.681  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eCallConnectionClearedEvent ), EnablementMask = 3f0000
01/21/14 13:27:31.682  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (CallTyp:2 EvtCause:65535 RelDevID:3945001 Msk:0x3f0000 UniqObjID:call.5000.16782414.5002  MsgID:eCallConnectionClearedEvent ICMEntUniqID:icm.150783.101 DevUniqObjID:device.5000.5002)
01/21/14 13:27:31.683  7464  CTIOSSoftphone  Thd(4332)  [call.5000.16782414.5002] eCallConnectionClearedEvent
01/21/14 13:27:31.707  7464  CTIOSSoftphone  Thd(4332)  ObjectId = call.5000.16782414.5002 , Enablement Mask = 3f0000
01/21/14 13:27:31.709  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eCallClearedEvent ), EnablementMask = 3f0000
01/21/14 13:27:31.710  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (CallTyp:2 EvtCause:65535 Msk:0x3f0000 UniqObjID:call.5000.16782414.5002  MsgID:eCallClearedEvent ICMEntUniqID:icm.150783.101 DevUniqObjID:device.5000.5002)
01/21/14 13:27:31.710  7464  CTIOSSoftphone  Thd(4332)  [call.5000.16782414.5002] eCallClearedEvent
01/21/14 13:27:31.723  7464  CTIOSSoftphone  Thd(4332)  ObjectId = call.5000.16782414.5002 , Enablement Mask = 3f0000
(call is ended)
01/21/14 13:27:31.725  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eCallEndEvent ), EnablementMask = ffffffff
01/21/14 13:27:31.725  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (CallTyp:2 DevID:5002 UniqObjID:call.5000.16782414.5002  MsgID:eCallEndEvent ICMEntUniqID:icm.150783.101 DevUniqObjID:device.5000.5002)
01/21/14 13:27:31.726  7464  CTIOSSoftphone  Thd(4332)  [call.5000.16782414.5002] eCallEndEvent
(Agent state is changed to available)
01/21/14 13:27:31.729  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent( eAgentStateEvent ), EnablementMask = 101b0000
01/21/14 13:27:31.729  7464  CTIOSSoftphone  Thd(4332)  CCtiOsSession::OnEvent, (PrphID:5000 PrphTyp:17 AGState:eAvailable SG#:25849 SGID:5000 StateDur:0 SGPri:0 EvtRsnCode:0 SGState:3 SessID:0 MRDID:1 ICMAGID:5003 AGMode:1 MaxTaskLim:1 NumTasks:0 AGExt:5002 AGID:9111 AGInstr:5002 CTIClntSig:CTIOSServer Msk:0x101b0000 UniqObjID:agent.5000.9111 MsgID:eAgentStateEvent DvrKey:agent.5000.9111 IncOrOut:21327 WrpupOKEnbl:1 AGAvailStatus:1)
01/21/14 13:27:31.729  7464  CTIOSSoftphone  Thd(4332)  [agent.5000.9111] eAgentStateEvent( eAvailable )

01/21/14 13:27:31.733  7464  CTIOSSoftphone  Thd(4332)  ObjectId = agent.5000.9111 , Enablement Mask = 101b0000

Cisco Unified SIP Proxy Log SIP Tracing and Trace Collection

Here are the Steps to enable SIP tracing using CUSP CLI for troubleshooting


CUSP
username <userid> create username <userid> password <password> username <userid> group pfs-privusers
cusp
trace enable
trace level debug component sip-wire-log
trace level debug
component routing
config
sip logging
end

To disable tracing do the following:
 cusp
config
no sip logging
end
trace level default
component sip-wire-log
trace level default
component routing
trace disable


Here is a guide to collect traces using Windows command prompt

 (ideal for environments where installing FTP clients are not permitted)


C:\Users\username>ftp
ftp> open x.x.x.x(CUSP IP address)

220 Welcome to Cisco FTP service.
User (10.1.125.219:(none)): xxxx(user created above
331 Please specify the password.
Password: xxxxx(password for user created)
230 Login successful.
*** Use the ls command to browse through the CUSP directory and obtain the correct path to the location of the sipmessage... log files***

Use the command below to change to the correct directory of the sipmessage log file

ftp> cd (directory)

ftp> get xxxx (sipmessage log name)

Use this command to see to confirm your local workstatinon local directory where the logs downloaded will be stored

ftp> lcd
Local directory now C:\Users\username>

Browse to the directory above to view your files

Thursday, January 16, 2014

CVP 8.0 Media Server Configuration- bad fetch error

While setting up a UCCE- CVP 8.0 lab, I encountered a "bad fetch" error causing prompts not to be played to caller. I discovered that after a basic CVP (all-in-one-box) installation additional configuration is needed for proper media server operation.

Here are my findings while troubleshooting:


Ingress/VXML gateway:

debug voip application vxml

Snippet

 //75//AFW_:/vapp_play_done: evID=178 reason=12, protocol=2, status_code=404, dur=0, rate=0
   CALL_ERROR; fail with vapp error 2, protocol_status_code=404
   CALL_ERROR; *** error.badfetch.http.404 event is thrown
*Jan 16 15:19:56.843:    expr=var _event='error.badfetch.http.404'

CVP Error Logs:

Media Fetch Error for URL=http://10.10.210.22/en-us/sys/Friday.wav (Client: 10.10.33.2) [id:3023]
520: 10.10.210.22: Jan 16 2014 05:09:43.893 -0600: %CVP_8_0_IVR-3-CALL_ERROR:  RunScript Error from 10.10.33.2 [MEDIA_FILE_NOT_FOUND(9)] CALLGUID: 9ABE08F2100001435354B2E90A0AD216 DNIS=811111111135 {VRUScriptName: 'PM,Friday,S' ConfigParam: ''} [id:3023]

IIS logs

Fields: date time s-ip cs-method cs-uri-stem cs-uri-query s-port cs-username c-ip cs(User-Agent) sc-status sc-substatus sc-win32-status

 10.10.210.22 GET /en-us/sys/Friday.wav - 80 - 10.10.33.2 Cisco-IOS-C2801/15.1 404 0 3
 10.10.210.22 GET /en-us/sys/Friday.wav - 80 - 10.10.33.2 Cisco-IOS-C2801/15.1 404 0 3


1. I entered  the URL on a web browser and also received a 404 error message.
2. I browsed to the path C:\Cisco\CVP\MediaFiles\en-us\sys and confirmed the Friday.wav file was there.
3. I checked the ICM script in monitor mode and notice the run ext. script node was failing to play the file.
4. I checked the IIS logs C:\WINDOWS\system32\LogFiles\W3SVC1 which ultimately proved that IIS was not finding the file.

Solution:

Configured the IIS home directory to match the location of the files(C:\Cisco\CVP\MediaFiles\)  from the default (C:\Inetpub\wwwroot.)





Added Permissions to Everyone to the file location folder.