Troubleshoot and Track Conference Agent Call in JTAPI GW

Introduction

This document describes how to track Agent events in JTAPI Gateway (JGW) logs in a conference call.

Prerequisites

Requirements

Cisco recommends that you have knowledge of these topics:

• Cisco Unified Contact Center Enterprise  (UCCE)
• Cisco Package Contact Center Enterprise  (PCCE)
• Cisco Unified Communications Manager (CUCM)

Components Used

The information in this document is based on these software and hardware versions:

• Unified Contact Center Enterprise Version 12.6(1)

The information in this document was created from the devices in a specific lab environment. All of the devices used in this document started with a cleared (default) configuration. If your network is live, ensure that you understand the potential impact of any command.

Background

The JTAPI Gateway (JGW) process is the one responsible to initialize communications with the CUCM through JTAPI. The main purpose is to track and monitor the agent events while an ACD call is getting delievered or if the agent is performing any of the task available from Finesse. The purpose of this document is to track an Agent trying to make a Conference call with another agent and what are the key points that can help troubleshoot these events.

Overview

Both agent phones are extensions on a CUCM and the caller is a PSTN number.

CUCM 192.168.10.10
Agent 1 Extension 1080
Agent 2 Extension 1082

Comprehensive Call Flow:

PSTN > CUBE > CVP > ICM > VVB > CUCM > Agent

Important Elements to take in consideration:

1) deviceName  --> Device Receiving the Call 
2) CallLegID -->  This is used to track the call in JGW trace
3) CallID --> Call ID generated for the Call 
4) CallActiveEv CID --> This CID can be mapped with CTISVR, OPC, PIM as well to track the call in ICM
5) State --> These are the states of the Call in JGW

Each Event have a Sequence Number. If JGW sends a request, youcan use the Sequence Number to track the response from CUCM CTI Manager.

High-Level Call Flow

1) PSTN Caller makes a call to the Toll Free Number (TFL) which hits CUBE and then CVP.
2) After going through the Comprehensive Call Flow, call gets routed to Agent 1 with extension 1080.
3) Agent 1 choose Consult in Finesse and Dials Agent 2 Extension 1082.
4) Once the Call is connected between both agents, Agent 1 hits Conference.
5) Once all parties are connected, the Conference takes place.

Troubleshoot 

Use these debug levels in order to troubleshoot the JGW messaging and the Session Initiation Protocol (SIP) signaling that corresponds on CUCM:

JTAPI

On the Agent Peripheral Gateway (PG), use the Procmon utility in order to turn up tracing for the JGW process:

C:\>procmon <cust_inst> <node> jgw<jtapi instance>
>>>trace JT_TPREQUESTS /on
>>>trace JT_JTAPI_EVENT_USED* /on
>>>trace JT_PIM_EVENT /on
>>>trace JT_ROUTE_MESSAGE /on
>>>trace *CONF* /on

<cust_inst> = CCE Instance.

<node> = This is the PG where you want to work on.

<jtapi instance> = Instance number assigned to the JGW process. You can find that number from Diagnostic Portico > Services > List Processes.

You can also use Diagnostic Framework Portico on the Agent PG and increase the trace level of the JGW process to 3. For that you go to Trace > Set Trace Level > Select the Component > Select the Level > Submit.

JTAPI States

-UnknownState 0

-IdleState 1
-OfferingState 2
-AcceptedState 3
-DialtoneState 4
-DialingState 5
-RingbackState 6
-BusyState 7
-ConnectedState 8
-ProceedingState 9
-OnHoldstate 10
-TransferOnpendingState 12
-TransferOnholdState 13
-DisconnectedState 14
-CallWaitingState 15
-RemoteInUseState 16
-ProgressingState 17
-WhisperState 18

Detailed Call Flow Analysis

Agent Received Call From PSTN and Shows State 2 as Offering.

7:18:17:959 pg3a-jgw1 Trace: 393: Jul 10 17:18:17.959 EDT %JTAPI-PROTOCOL-7-UNK:(P1-192.168.10.10) received Event: com.cisco.cti.protocol.NewCallEvent {

eventSequence = 61236.
17:18:17:959 pg3a-jgw1 Trace:
lineCallManagerID = 1
lineID = 32
lineHandleSpecified = true
deviceName = UCSFSJEFFERS.
17:18:17:959 pg3a-jgw1 Trace:
callCallManagerID = 1
callLegID = 27308081
globalCallManagerID = 1
callID = 7470099.
17:18:17:959 pg3a-jgw1 Trace:
callingParty = <PSTN NUMBER>
calledParty = 1080
originalCalledParty = 1080
state = 2.

17:18:17:959 pg3a-jgw1 Trace: 396: Jul 10 17:18:17.959 EDT %JTAPI-PROTOCOL-7-UNK:(P1-192.168.10.10) received Event: com.cisco.cti.protocol.CallStateChangedEvent_V2 {
eventSequence = 61237.
17:18:17:959 pg3a-jgw1 Trace:
lineCallManagerID = 1
lineID = 32
callCallManagerID = 1
callLegID = 27308081
state = 2.

17:18:17:959 pg3a-jgw1 Trace: CallActiveEv CID: 24247315.

17:18:17:959 pg3a-jgw1 Trace: ConnCreatedEv CID: 24247315 (7470099/1) Addr: 1080 CurCalling: 5555551234 CurCallingURLType: URL_TYPE_UNKNOWN CurCalled: 1080 CurCalledURLType: URL_TYPE_SIP Calling: 5555551234 Called: 1080 Cause: NORMAL.

Call Changed to Accepted State.

17:18:18:006 pg3a-jgw1 Trace: 438: Jul 10 17:18:18.006 EDT %JTAPI-PROTOCOL-7-UNK:(P1-192.168.10.10) received Event: com.cisco.cti.protocol.CallStateChangedEvent_V2 {
eventSequence = 61238.
17:18:18:006 pg3a-jgw1 Trace:
lineCallManagerID = 1
lineID = 32
callCallManagerID = 1
callLegID = 27308081
state

JGW sends the Answer request. You can see Sequence Number 11057. You receive a response with that Sequence Number.

17:18:20:653 pg3a-jgw1 Trace: 462: Jul 10 17:18:20.653 EDT %JTAPI-PROTOCOL-7-UNK:(P1-192.168.10.10) [GW-ThreadAnswerCall] sending: com.cisco.cti.protocol.CallAnswerRequest {
sequenceNumber = 11057.
17:18:20:653 pg3a-jgw1 Trace:
lineCallManagerID = 1
lineID = 32
callLegCallManagerID = 1
callLegID = 27308081
mediaDeviceName =
mediaResourceId = 0

}.

17:18:20:784 pg3a-jgw1 Trace: 463: Jul 10 17:18:20.784 EDT %JTAPI-PROTOCOL-7-UNK:(P1-192.168.10.10) received Response: com.cisco.cti.protocol.CallAnswerResponse {
sequenceNumber = 11057
result = 0
}.

Since the call was accpeted, you start seeing the Start Transmission and Reception, meaning RTP is getting connected.

17:18:20:784 pg3a-jgw1 Trace: 464: Jul 10 17:18:20.784 EDT %JTAPI-PROTOCOL-7-UNK:(P1-192.168.10.10) received Event: com.cisco.cti.protocol.StartTransmissionEvent {

eventSequence = 61239
deviceCallManagerID = 1.
17:18:20:784 pg3a-jgw1 Trace:
deviceID = 34
callCallManagerID = 1
callLegID = 27308081
ipAddr = -494595386
rtpPortNumber = 8980.


17:18:20:784 pg3a-jgw1 Trace: 467: Jul 10 17:18:20.784 EDT %JTAPI-PROTOCOL-7-UNK:(P1-192.168.10.10) received Event: com.cisco.cti.protocol.StartReceptionEvent {

eventSequence = 61240
deviceCallManagerID = 1.
17:18:20:784 pg3a-jgw1 Trace:
deviceID = 34
callCallManagerID = 1
callLegID = 27308081
ipAddr = 1267012294
rtpPortNumber = 20704.

Call Change to State 8, Meaning Connected.

17:18:20:784 pg3a-jgw1 Trace: 482: Jul 10 17:18:20.784 EDT %JTAPI-PROTOCOL-7-UNK:(P1-192.168.10.10) received Event: com.cisco.cti.protocol.CallStateChangedEvent_V2 {
eventSequence = 61242.
17:18:20:784 pg3a-jgw1 Trace:
lineCallManagerID = 1
lineID = 32
callCallManagerID = 1
callLegID = 27308081
state = 8.

When the agent wants to do a Consult Transfer (Conference) you see the request being sent to CUCM, and you see a result of the sequence coming back from CUCM.

17:19:28:463 pg3a-jgw1 Trace: 780: Jul 10 17:19:28.463 EDT %JTAPI-PROTOCOL-7-UNK:(P1-192.168.10.10) [GW-ThreadConsultationCall] sending: com.cisco.cti.protocol.CallSetupTransferRequest {
sequenceNumber = 11062.
17:19:28:463 pg3a-jgw1 Trace:
lineCallManagerID = 1
lineID = 32
callLegCallManagerID = 1
callLegID = 27308081.
17:19:28:463 pg3a-jgw1 Trace:
newCallManagerID = 1
newGlobalCallID = 7470101
callingAddress = null
destAddress = 1082.
17:19:28:463 pg3a-jgw1 Trace:
userData = null
bNeverConnectMediaForConsultCall = false
}.

17:19:28:595 pg3a-jgw1 Trace: 791: Jul 10 17:19:28.595 EDT %JTAPI-PROTOCOL-7-UNK:(P1-192.168.10.10) received Response: com.cisco.cti.protocol.CallSetupTransferResponse {
sequenceNumber = 11062
result = 0.

Caller Transition to Hold, Which is State 10.

17:19:28:595 pg3a-jgw1 Trace: 781: Jul 10 17:19:28.595 EDT %JTAPI-PROTOCOL-7-UNK:(P1-192.168.10.10) received Event: com.cisco.cti.protocol.CallStateChangedEvent_V2 {
eventSequence = 61255.
17:19:28:595 pg3a-jgw1 Trace:
lineCallManagerID = 1
lineID = 32
callCallManagerID = 1
callLegID = 27308081
state

A new Call gets Generated by the Agent. You Can use the New CallLeg to Track this New Call to the Other User.

17:19:28:595 pg3a-jgw1 Trace: 797: Jul 10 17:19:28.595 EDT %JTAPI-PROTOCOL-7-UNK:(P1-192.168.10.10) received Event: com.cisco.cti.protocol.NewCallEvent {

eventSequence = 61257.
17:19:28:595 pg3a-jgw1 Trace:
lineCallManagerID = 1
lineID = 32
lineHandleSpecified = true
deviceName = UCSFSJEFFERS.
17:19:28:595 pg3a-jgw1 Trace:
callCallManagerID = 1
callLegID = 27308086
globalCallManagerID = 1
callID = 7470101.
17:19:28:595 pg3a-jgw1 Trace:
callingParty = 1080
calledParty =
originalCalledParty =
state = 4.

17:19:28:879 pg3a-jgw1 Trace: 883: Jul 10 17:19:28.879 EDT %JTAPI-PROTOCOL-7-UNK:(P1-192.168.10.10) received Event: com.cisco.cti.protocol.CallPartyInfoChangedEvent {
eventSequence = 61262.
17:19:28:879 pg3a-jgw1 Trace:
lineCallManagerID = 1
lineID = 32
callCallManagerID = 1
callLegID = 27308086.
17:19:28:879 pg3a-jgw1 Trace:
callingPartyChanged = false
callingParty = 1080
callingPartyName =
calledPartyChanged = true.
17:19:28:879 pg3a-jgw1 Trace:
calledParty = 1082

Once the Other Agent Answers, Call Gets Connected.

17:19:32:828 pg3a-jgw1 Trace: 1017: Jul 10 17:19:32.828 EDT %JTAPI-PROTOCOL-7-UNK:(P1-192.168.10.10) received Event: com.cisco.cti.protocol.CallStateChangedEvent_V2 {
eventSequence = 61278.
17:19:32:828 pg3a-jgw1 Trace:
lineCallManagerID = 1
lineID = 32
callCallManagerID = 1
callLegID = 27308086
state = 8.

17:19:32:844 pg3a-jgw1 Trace: 1074: %JTAPI-CTI-7-UNK:(P1-PG_USER){Line:UCSFSJEFFERS:1080:Everyone:(1,32)|Call:[GCID=(7470101/1),CID=27308086]} CallStateChanged (V2) [state=CONNECTED cause=NOERROR destType=IN_CLUSTER destCM=0 fwdD.

Then Agent Join the Callers Into the Conference. You See the Sequence Number and the Response from CUCM.

17:19:46:393 pg3a-jgw1 Trace: MsgConferenceCall: HeldCID: 24247315 HeldConnDevID: 1080/0 ActiveCID: 24247317 ActiveConnDevID: 1080/0 DialedNum: InvID: 120563.

17:19:46:393 pg3a-jgw1 Trace: 1079: %JTAPI-JTAPI-7-UNK:(P1-PG_USER)[GW-ThreadConferenceCall][(P1-PG_USER) GCID=(1,7470099)->ACTIVE]Request: conference((P1-PG_USER) GCID=(1,7470101)->ACTIVE).
17:19:46:393 pg3a-jgw1 Trace: 1080: %JTAPI-JTAPI-7-UNK:[7470099/1]conference(): conference controller 1: [UCSFSJEFFERS/[1080:Everyone:1/(P1-PG_USER) GCID=(1,7470099)->ACTIVE]->ESTABLISHED]->HELD, conference controller 2: [UCSFSJE.
17:19:46:393 pg3a-jgw1 Trace: FFERS/[1080:Everyone:1/(P1-PG_USER) GCID=(1,7470101)->ACTIVE]->ESTABLISHED]->TALKING.
17:19:46:393 pg3a-jgw1 Trace: 1081: %JTAPI-JTAPI-7-UNK:[(P1-PG_USER) GCID=(1,7470099)->ACTIVE]conference ((P1-PG_USER) GCID=(1,7470101)->ACTIVE,[UCSFSJEFFERS/[1080:Everyone:1/(P1-PG_USER) GCID=(1,7470099)->ACTIVE]->ESTABLISHED]->.
17:19:46:393 pg3a-jgw1 Trace: HELD,[UCSFSJEFFERS/[1080:Everyone:1/(P1-PG_USER) GCID=(1,7470101)->ACTIVE]->ESTABLISHED]->TALKING).
17:19:46:393 pg3a-jgw1 Trace: 1082: %JTAPI-JTAPIIMPL-7-UNK:[Call:[GCID=(7470099/1),CID=27308081]]calling call.join(Call:[GCID=(7470101/1),CID=27308086])..
17:19:46:393 pg3a-jgw1 Trace: 1083: Jul 10 17:19:46.393 EDT %JTAPI-PROTOCOL-7-UNK:(P1-192.168.10.10) [GW-ThreadConferenceCall] sending: com.cisco.cti.protocol.CallJoinRequest {

sequenceNumber = 11064.
17:19:46:393 pg3a-jgw1 Trace:
lineCallManagerID = 1
lineID = 32
callLegCallManagerID = 1
callLegID = 27308081
otherCalls = 1@[.
17:19:46:393 pg3a-jgw1 Trace:
com.cisco.cti.protocol.ClientCallHandle {CallManagerId=1
CallLegId=27308086
}]
}.

17:19:46:477 pg3a-jgw1 Trace: 1123: Jul 10 17:19:46.477 EDT %JTAPI-PROTOCOL-7-UNK:(P1-192.168.10.10) received Response: com.cisco.cti.protocol.CallJoinResponse {
sequenceNumber = 11064
result = 0
}.

Once all Parties Join, the New Conference Starts and the Start Transmission and Start Reception Happen to All Parties Involved (PSTN Caller and 2 Agents).

17:19:46:477 pg3a-jgw1 Trace: primaryConnectionMyConn: GenID: 20193 IDVal: 27308081 Dev: 1080/0 Ext: 1080 DevTgStr: 1080 Addr: 1080 State: CONNECTED CCState: ESTABLISHED prevCCState: ESTABLISHED loggedIn: Y reportedToOPC: Y.
17:19:46:477 pg3a-jgw1 Trace: secondaryConnectionMyConn: GenID: 20198 IDVal: 27308088 Dev: 1082/0 Ext: 1082 DevTgStr: 1082 Addr: 1082 State: CONNECTED CCState: ESTABLISHED prevCCState: ESTABLISHED loggedIn: Y reportedToOPC: Y.
17:19:46:477 pg3a-jgw1 Trace: CiscoConferenceStart: CID: 24247315 (7470099/1) ConfCID: 24247317 (7470101/1) FinCID: 24247315 (7470099/1).

17:19:47:725 pg3a-jgw1 Trace: 1299: Jul 10 17:19:47.725 EDT %JTAPI-PROTOCOL-7-UNK:(P1-192.168.10.10) received Event: com.cisco.cti.protocol.CallConferenceStateChangedEvent {

eventSequence = 61299.
17:19:47:725 pg3a-jgw1 Trace:

lineCallManagerID = 1

lineID = 32

callCallManagerID = 1

callLegID = 27308081

conferenceStateChangedID = 2.
17:19:47:725 pg3a-jgw1 Trace:

globalCallManagerID = 1

globalCallID = 7470099

modifyStatus = 1

17:19:47:740 pg3a-jgw1 Trace: 1396: %JTAPI-CTI-7-UNK:Call:[GCID=(7470099/1),CID=27308081] On Device:(P1-PG_USER) UCSFSJEFFERS(1,34) StartTransmission MediaConnectionMode:3.

17:19:47:740 pg3a-jgw1 Trace: 1401: %JTAPI-CTI-7-UNK:Call:[GCID=(7470099/1),CID=27308081] On Device:(P1-PG_USER) UCSFSJEFFERS(1,34) StartReception MediaConnectionMode:3.

Once One of the Parties Ends the call, the Conference changes state.

17:19:47:725 pg3a-jgw1 Trace: 1299: Jul 10 17:19:47.725 EDT %JTAPI-PROTOCOL-7-UNK:(P1-192.168.10.10) received Event: com.cisco.cti.protocol.CallConferenceStateChangedEvent {

eventSequence = 61299.
17:19:47:725 pg3a-jgw1 Trace:
lineCallManagerID = 1
lineID = 32
callCallManagerID = 1
callLegID = 27308081
conferenceStateChangedID = 2.
17:19:47:725 pg3a-jgw1 Trace:
globalCallManagerID = 1
globalCallID = 7470099
modifyStatus = 1

You see the LineConferenceEndedEvent Coming from CUCM and the CallLeg that Ended their call.

17:19:47:725 pg3a-jgw1 Trace: 1301: Jul 10 17:19:47.725 EDT %JTAPI-PROTOCOL-7-UNK:(P1-192.168.10.10) received Event: com.cisco.cti.protocol.LineConferenceEndedEvent {
eventSequence = 61300.
17:19:47:725 pg3a-jgw1 Trace:
lineCallManagerID = 1
lineID = 32
transactionID = 16777217
success = true.
17:19:47:725 pg3a-jgw1 Trace:
bRemoteInUse = false
idleCalls = 1@[
com.cisco.cti.protocol.CtiCallHandle {
callManagerID = 1
callLegID = 27308086
}].

Now a New Connection Gets Created with the Remaining Parties.

17:19:47:725 pg3a-jgw1 Trace: 1309: %JTAPI-JTAPIIMPL-7-UNK:{(P1-PG_USER) GCID=(1,7470099)->ACTIVE} CallManager.conferenceCall: Creating new connection for conferenced party.

17:19:47:725 pg3a-jgw1 Trace: CiscoCallChangedEv CID: 24247317 Addr: 1082 Surviving Call ID: 24247315 (7470099/1) Surviving Calling Address: 5555551234 Surviving Called Address: 1080 Original Call ID: 24247317 (7470101/1) Original Calling Address: 1080 Original Called Address: 1082 CiscoC.

17:19:47:725 pg3a-jgw1 Trace: 1354: %JTAPI-JTAPIIMPL-7-UNK:{(P1-PG_USER) GCID=(1,7470099)->ACTIVE} Handling External STATE_CONNECTED for 5555551234::2.

17:19:47:725 pg3a-jgw1 Trace: 1371: %JTAPI-JTAPIIMPL-7-UNK:[ FinalCall=(P1-PG_USER) GCID=(1,7470099)->ACTIVE ]CiscoConferenceEndEv event.Success=true.

A New Start Reception and Start Transmission is Received for this New Connection.

17:19:47:725 pg3a-jgw1 Trace: 1391: Jul 10 17:19:47.725 EDT %JTAPI-PROTOCOL-7-UNK:(P1-192.168.10.10) received Event: com.cisco.cti.protocol.StartTransmissionEvent {
eventSequence = 61301
deviceCallManagerID = 1.
17:19:47:725 pg3a-jgw1 Trace:
deviceID = 34
callCallManagerID = 1
callLegID = 27308081
ipAddr = 59052742
rtpPortNumber = 26320.


17:19:47:740 pg3a-jgw1 Trace: 1394: Jul 10 17:19:47.725 EDT %JTAPI-PROTOCOL-7-UNK:(P1-192.168.10.10) received Event: com.cisco.cti.protocol.StartReceptionEvent {
eventSequence = 61302
deviceCallManagerID = 1.
17:19:47:740 pg3a-jgw1 Trace:
deviceID = 34
callCallManagerID = 1
callLegID = 27308081
ipAddr = 1267012294
rtpPortNumber = 20704.

As Soon as the Call Finish Between the Remaining Parties, You See the Disconnect Request Sent as well as the ConferenceStateChangeEvent.

17:20:07:835 pg3a-jgw1 Trace: 1521: Jul 10 17:20:07.835 EDT %JTAPI-PROTOCOL-7-UNK:(P1-192.168.10.10) [GW-ThreadClearConnection] sending: com.cisco.cti.protocol.CallDisconnectRequest {
sequenceNumber = 11065.
17:20:07:835 pg3a-jgw1 Trace:
lineCallManagerID = 1
lineID = 32
callLegCallManagerID = 1
callLegID = 27308081
}.

17:20:07:835 pg3a-jgw1 Trace: 1522: Jul 10 17:20:07.835 EDT %JTAPI-PROTOCOL-7-UNK:(P1-192.168.10.10) received Response: com.cisco.cti.protocol.CallDisconnectResponse {
sequenceNumber = 11065
result = 0
}.

17:20:07:881 pg3a-jgw1 Trace: 1523: Jul 10 17:20:07.881 EDT %JTAPI-PROTOCOL-7-UNK:(P1-192.168.10.10) received Event: com.cisco.cti.protocol.CallConferenceStateChangedEvent {
eventSequence = 61308.
17:20:07:881 pg3a-jgw1 Trace:
lineCallManagerID = 1
lineID = 80
callCallManagerID = 1
callLegID = 27308088
conferenceStateChangedID = 4.
17:20:07:881 pg3a-jgw1 Trace:
globalCallManagerID = 1
globalCallID = 7470099
modifyStatus = 2

Finally You Receive the Stop Reception and Transmission for RTP.

17:20:07:881 pg3a-jgw1 Trace: 1526: Jul 10 17:20:07.881 EDT %JTAPI-PROTOCOL-7-UNK:(P1-192.168.10.10) received Event: com.cisco.cti.protocol.StopReceptionEvent {
eventSequence = 61309
deviceCallManagerID = 1.
17:20:07:881 pg3a-jgw1 Trace:
deviceID = 34
callCallManagerID = 1
callLegID = 27308081
mediaDeviceName =
mediaResourceId = 0
mediaConnectionMode = 3
}.

17:20:07:881 pg3a-jgw1 Trace: 1528: Jul 10 17:20:07.881 EDT %JTAPI-PROTOCOL-7-UNK:(P1-192.168.10.10) received Event: com.cisco.cti.protocol.StopTransmissionEvent {
eventSequence = 61310
deviceCallManagerID = 1.
17:20:07:881 pg3a-jgw1 Trace:
deviceID = 34
callCallManagerID = 1
callLegID = 27308081
mediaDeviceName =
mediaResourceId = 0
mediaConnectionMode = 3
}.

Call Change State with the Disconnect Cause, in Our example 16 as Normal Call Clearing.

17:20:07:897 pg3a-jgw1 Trace: 1536: Jul 10 17:20:07.897 EDT %JTAPI-PROTOCOL-7-UNK:(P1-192.168.10.10) received Event: com.cisco.cti.protocol.CallStateChangedEvent_V2 {

eventSequence = 61313.
17:20:07:897 pg3a-jgw1 Trace:

lineCallManagerID = 1

lineID = 32

callCallManagerID = 1

callLegID = 27308081

state = 1.
17:20:07:897 pg3a-jgw1 Trace:

cause = 16