" /> Call can not be Released While TServer Switchover - Invalid Connection Id - Genesys CTI User Forum

Author Topic: Call can not be Released While TServer Switchover - Invalid Connection Id  (Read 4676 times)

Offline nisargmca

  • Newbie
  • *
  • Posts: 4
  • Karma: 0
Advertisement
Hi All,

Please consider below scenario :
[1] Our Application (Softphone) is Connected to Primary T Server .
[2] While Call is landed on Softphone ,Primary T Server goes down and Softphone connects to secondary T Server using warm stand by.
[3] After Softphone connects to Secondary TServer ,when trying to End the call using [b]RequestReleaseCall[/b] which takes DN and Current ConnectionId . Its throwing "Invalid Connection Id"

Here is the portion of logs (My apology to paste logs here .when i tried to attach log file of 4kb it has given me error.)

Here is the EventRinging value on Primary TServer
-------------------------------------------------------

[code]{11:05:12; 17:14:36.156} DEBUG [Selector#0    ] [me.ProtocolMessagePackagerImpl]  New message #60
{11:05:12; 17:14:36.171} DEBUG [Selector#0    ] [ol.runtime.ConnectionProxyImpl]  Proxy got message EventRinging. Processing with  state .StatePrimary@eebf17 proxy: proxy1
{11:05:12; 17:14:36.171} DEBUG [Selector#0    ] [.protocol.runtime.StatePrimary]  Checking message in primary: EventRinging
{11:05:12; 17:14:36.171} DEBUG [Selector#0    ] [.protocol.runtime.HAConnection]  notifying channel handler
{11:05:12; 17:14:36.171} DEBUG [Selector#0    ] [me.ProtocolMessagePackagerImpl]  New message #86
{11:05:12; 17:14:36.171} DEBUG [.defaultInvoker] [mons.broker.EventBrokerService]  Publishing {0} ...'EventRinging' (60) attributes:
AttributeExtensions [bstr] = KVList:
'UCID' [bstr] =
  0x9e 0xfb 0xac 0x4f 0x2e 0x3a 0x01 0x00
AttributeNetworkDestDN [str] = "smithfield_10::7245641101"
AttributeCallType [int] = 2 [Inbound]
AttributeOtherDNRole [int] = 1 [RoleOrigination]
AttributeThisQueue [str] = "7245646821"
AttributeConnID [long] = 00ab020611a40280
AttributeOtherDN [str] = "912040601000"
AttributeFirstTransferConnID [long] = 00ab020611a40280
AttributeUserData [bstr] = KVList:
'ACCT_STATUS_CD' [str] = "ACTIVE"
'CALL_SUB_CD' [str] = "001"
'CALL_TYP_CD' [str] = "20000"
'CUST_ACCT_NUM' [str] = "14775063001"
'CUST_COMPANY' [str] = "ColumbiaOH"
'CUST_PHN_NBR' [str] = "8667214052"
'IVRANI' [str] = "8667214052"
'IVRDNIS' [str] = "7704"
'PHONE_VERIFY' [str] = "Y"
'SITE_ID' [str] = "200514585"
'SSN_AUTH' [str] = "N"
'STMT_DUE_DT' [str] = "04192012"
AttributeThisDN [str] = "7245641507"
AttributeAgentID [str] = "7245645626"
AttributeDNIS [str] = "1108"
AttributeThisDNRole [int] = 2 [RoleDestination]
AttributeCallUuid [str] = "01R39PNPESFQP67N04000VTAES000006"
AttributePropagatedCallType [int] = 2 [Inbound]
AttributeANI [str] = "912040601000"
AttributeNetworkPartyRole [int] = 2 [RoleNtwDestParty]
AttributeLastTransferConnID [long] = 00ab020611a40280
AttributeNetworkCallID [long] = 1336736670
AttributeCallID [int] = 14894
AttributeEventSequenceNumber [long] = 89
AttributeCause [int] = 1 [ACD]
AttributeCallState [int] = 0
AttributeThisTrunk [int] = 7930073
TimeStamp:
AttributeTimeinSecs [int] = 1336736674
AttributeTimeinuSecs [int] = 983130
CallHistoryInfo:
LastRemoteParty:
AttributeLastTransferOrigDN [str] = "201"
AttributeLastTransferHomeLocation [str] = "IVR_Server72_2@IVR_Farm2_Switch"
FirstRemoteParty:
AttributeFirstTransferOrigDN [str] = "201"
AttributeFirstTransferHomeLocation [str] = "IVR_Server72_2@IVR_Farm2_Switch"
{11:05:12; 17:14:36.187} DEBUG [.defaultInvoker] [mons.broker.EventBrokerService]  Notifying 20 subscribers...
{11:05:12; 17:14:36.187} DEBUG [.defaultInvoker] [urce.softphone.CallDataManager]  ****Attached Data size 12 ConnId 00ab020611a40280 Call ID 14894 ANI 912040601000 DNIS 1108
{11:05:12; 17:14:36.187} DEBUG [.defaultInvoker] [urce.softphone.CallDataManager]  Queue:7245646821: CallType :00000:000
{11:05:12; 17:14:36.187} DEBUG [.defaultInvoker] [urce.softphone.CallDataManager]  Keys:  Key ACCT_STATUS_CD Value ACTIVE Key CALL_SUB_CD Value 001 Key CALL_TYP_CD Value 20000 Key CUST_ACCT_NUM Value 14775063001 Key CUST_COMPANY Value ColumbiaOH Key CUST_PHN_NBR Value 8667214052 Key IVRANI Value 8667214052 Key IVRDNIS Value 7704 Key PHONE_VERIFY Value Y Key SITE_ID Value 200514585 Key SSN_AUTH Value N Key STMT_DUE_DT Value 04192012 datamap {CUST_ACCT_NUM=14775063001, IVRANI=8667214052, telcoEvent=EventRinging, CUST_COMPANY=ColumbiaOH, CALL_SUB_CD=001, CALL_TYP_CD=20000, GENESYS_ANI=912040601000, CALL_ID=14894, IVRDNIS=7704, SITE_ID=200514585, CUST_PHN_NBR=8667214052, GENESYS_DNIS=1108, PHONE_VERIFY=Y, CONN_ID=00ab020611a40280, STMT_DUE_DT=04192012, ACCT_STATUS_CD=ACTIVE, SSN_AUTH=N, GENESYS_CONNID=00ab020611a40280, GENESYS_EVENT=EventRinging, GENESYS_CALLID=14894}
{11:05:12; 17:14:36.187} DEBUG [.defaultInvoker] [m.ibm.nisource.softphone.Phone]  ChangeLineState 0 Status EventRinging
{11:05:12; 17:14:36.187} DEBUG [.defaultInvoker] [m.ibm.nisource.softphone.Phone]  LineState Idle
{11:05:12; 17:14:36.187} DEBUG [.defaultInvoker] [m.ibm.nisource.softphone.Phone]  setPhoneStatus Ringing-Call CSRState Ready dial null
{11:05:12; 17:14:36.187} DEBUG [.defaultInvoker] [mons.broker.EventBrokerService]  20 subscribers notified
{11:05:12; 17:14:36.187} DEBUG [Selector#0    ] [ol.runtime.ConnectionProxyImpl]  Proxy got message EventOffHook. Processing with  state .StatePrimary@eebf17 proxy: proxy1
{11:05:12; 17:14:36.187} DEBUG [.defaultInvoker] [mons.broker.EventBrokerService]  Publishing {0} is completed.'EventRinging' (60) attributes:
AttributeExtensions [bstr] = KVList:
'UCID' [bstr] =
  0x9e 0xfb 0xac 0x4f 0x2e 0x3a 0x01 0x00
AttributeNetworkDestDN [str] = "smithfield_10::7245641101"
AttributeCallType [int] = 2 [Inbound]
AttributeOtherDNRole [int] = 1 [RoleOrigination]
AttributeThisQueue [str] = "7245646821"
AttributeConnID [long] = 00ab020611a40280
AttributeOtherDN [str] = "912040601000"
AttributeFirstTransferConnID [long] = 00ab020611a40280
AttributeUserData [bstr] = KVList:
'ACCT_STATUS_CD' [str] = "ACTIVE"
'CALL_SUB_CD' [str] = "001"
'CALL_TYP_CD' [str] = "20000"
'CUST_ACCT_NUM' [str] = "14775063001"
'CUST_COMPANY' [str] = "ColumbiaOH"
'CUST_PHN_NBR' [str] = "8667214052"
'IVRANI' [str] = "8667214052"
'IVRDNIS' [str] = "7704"
'PHONE_VERIFY' [str] = "Y"
'SITE_ID' [str] = "200514585"
'SSN_AUTH' [str] = "N"
'STMT_DUE_DT' [str] = "04192012"
AttributeThisDN [str] = "7245641507"
AttributeAgentID [str] = "7245645626"
AttributeDNIS [str] = "1108"
AttributeThisDNRole [int] = 2 [RoleDestination]
AttributeCallUuid [str] = "01R39PNPESFQP67N04000VTAES000006"
AttributePropagatedCallType [int] = 2 [Inbound]
AttributeANI [str] = "912040601000"
AttributeNetworkPartyRole [int] = 2 [RoleNtwDestParty]
AttributeLastTransferConnID [long] = 00ab020611a40280
AttributeNetworkCallID [long] = 1336736670
AttributeCallID [int] = 14894
AttributeEventSequenceNumber [long] = 89
AttributeCause [int] = 1 [ACD]
AttributeCallState [int] = 0
AttributeThisTrunk [int] = 7930073
TimeStamp:
AttributeTimeinSecs [int] = 1336736674
AttributeTimeinuSecs [int] = 983130
CallHistoryInfo:
LastRemoteParty:
AttributeLastTransferOrigDN [str] = "201"
AttributeLastTransferHomeLocation [str] = "IVR_Server72_2@IVR_Farm2_Switch"
FirstRemoteParty:
AttributeFirstTransferOrigDN [str] = "201"
AttributeFirstTransferHomeLocation [str] = "IVR_Server72_2@IVR_Farm2_Switch"
{11:05:12; 17:14:36.187} DEBUG [Selector#0    ] [.protocol.runtime.StatePrimary]  Checking message in primary: EventOffHook
{11:05:12; 17:14:36.187} DEBUG [Selector#0    ] [.protocol.runtime.HAConnection]  notifying channel handler
{11:05:12; 17:14:36.187} DEBUG [Selector#0    ] [me.ProtocolMessagePackagerImpl]  New message #64
{11:05:12; 17:14:36.187} DEBUG [.defaultInvoker] [mons.broker.EventBrokerService]  Publishing {0} ...'EventOffHook' (86) attributes:
AttributeThisDN [str] = "7245641507"
AttributeEventSequenceNumber [long] = 90
TimeStamp:
AttributeTimeinSecs [int] = 1336736674
AttributeTimeinuSecs [int] = 983425
CallHistoryInfo:
LastRemoteParty:
FirstRemoteParty:
{11:05:12; 17:14:36.187} DEBUG [.defaultInvoker] [mons.broker.EventBrokerService]  Notifying 20 subscribers...
{11:05:12; 17:14:36.187} DEBUG [.defaultInvoker] [mons.broker.EventBrokerService]  20 subscribers notified
{11:05:12; 17:14:36.187} DEBUG [.defaultInvoker] [mons.broker.EventBrokerService]  Publishing {0} is completed.'EventOffHook' (86) attributes:
AttributeThisDN [str] = "7245641507"
AttributeEventSequenceNumber [long] = 90
TimeStamp:
AttributeTimeinSecs [int] = 1336736674
AttributeTimeinuSecs [int] = 983425
CallHistoryInfo:
LastRemoteParty:
FirstRemoteParty:
{11:05:12; 17:14:36.218} DEBUG [Selector#0    ] [ol.runtime.ConnectionProxyImpl]  Proxy got message EventEstablished. Processing with  state .StatePrimary@eebf17 proxy: proxy1
{11:05:12; 17:14:36.218} DEBUG [Selector#0    ] [.protocol.runtime.StatePrimary]  Checking message in primary: EventEstablished
{11:05:12; 17:14:36.218} DEBUG [Selector#0    ] [.protocol.runtime.HAConnection]  notifying channel handler
{11:05:12; 17:14:36.218} DEBUG [Selector#0    ] [me.ProtocolMessagePackagerImpl]  New message #69
{11:05:12; 17:14:36.218} DEBUG [.defaultInvoker] [mons.broker.EventBrokerService]  Publishing {0} ...'EventEstablished' (64) attributes:
AttributeExtensions [bstr] = KVList:
'UCID' [bstr] =
  0x9e 0xfb 0xac 0x4f 0x2e 0x3a 0x01 0x00
AttributeNetworkDestDN [str] = "smithfield_10::7245641101"
AttributeCallType [int] = 2 [Inbound]
AttributeOtherDNRole [int] = 1 [RoleOrigination]
AttributeThisQueue [str] = "7245646821"
AttributeConnID [long] = 00ab020611a40280
AttributeOtherDN [str] = "912040601000"
AttributeFirstTransferConnID [long] = 00ab020611a40280
AttributeUserData [bstr] = KVList:
'ACCT_STATUS_CD' [str] = "ACTIVE"
'CALL_SUB_CD' [str] = "001"
'CALL_TYP_CD' [str] = "20000"
'CUST_ACCT_NUM' [str] = "14775063001"
'CUST_COMPANY' [str] = "ColumbiaOH"
'CUST_PHN_NBR' [str] = "8667214052"
'IVRANI' [str] = "8667214052"
'IVRDNIS' [str] = "7704"
'PHONE_VERIFY' [str] = "Y"
'SITE_ID' [str] = "200514585"
'SSN_AUTH' [str] = "N"
'STMT_DUE_DT' [str] = "04192012"
AttributeThisDN [str] = "7245641507"
AttributeAgentID [str] = "7245645626"
AttributeDNIS [str] = "1108"
AttributeThisDNRole [int] = 2 [RoleDestination]
AttributeCallUuid [str] = "01R39PNPESFQP67N04000VTAES000006"
AttributePropagatedCallType [int] = 2 [Inbound]
AttributeANI [str] = "912040601000"
AttributeNetworkPartyRole [int] = 2 [RoleNtwDestParty]
AttributeLastTransferConnID [long] = 00ab020611a40280
AttributeNetworkCallID [long] = 1336736670
AttributeCallID [int] = 14894
AttributeEventSequenceNumber [long] = 91
AttributeCallState [int] = 0
AttributeThisTrunk [int] = 7930073
TimeStamp:
AttributeTimeinSecs [int] = 1336736674
AttributeTimeinuSecs [int] = 983489
CallHistoryInfo:
LastRemoteParty:
AttributeLastTransferOrigDN [str] = "201"
AttributeLastTransferHomeLocation [str] = "IVR_Server72_2@IVR_Farm2_Switch"
FirstRemoteParty:
AttributeFirstTransferOrigDN [str] = "201"
AttributeFirstTransferHomeLocation [str] = "IVR_Server72_2@IVR_Farm2_Switch"[/code]


-------------------------------------------------------------------------------------------------------------------------

When It Connects to Secondary TServer .Here is the logs for that including EventError



[code]{11:05:12; 17:16:42.562} DEBUG [Selector#0    ] [ection.impl.AbstractConnection]  Forcing connection close. Connection: tcp://10.101.160.89:8001[Opening]/5
{11:05:12; 17:16:42.562} DEBUG [Selector#0    ] [mux.MultiplexingConnectionImpl]  Closing MConnection: tcp://10.101.160.89:8001[Opening]/5
{11:05:12; 17:16:42.562} DEBUG [Selector#0    ] [ection.impl.AbstractConnection]  ConnState transition. 'Opening' -> 'Closed' for 'tcp://10.101.160.89:8001[Closed]/5
{11:05:12; 17:16:42.562} DEBUG [Selector#0    ] [ection.impl.AbstractConnection]  ConnState transition. 'Opening' -> 'Closed' for 'tcp://10.101.160.89:8001[Closed]/4 - HA
{11:05:12; 17:16:42.562} DEBUG [Selector#0    ] [ocol.runtime.TransitionManager]  Transition from '.StateOpening@1a3f178 proxy: proxy1' to '.StateAbsent@118a770 proxy: proxy1
{11:05:12; 17:16:42.562} DEBUG [Selector#0    ] [ol.runtime.ConnectionProxyImpl]  Setting connection: null
{11:05:12; 17:16:42.562} DEBUG [invoker.default] [mmons.timer.impl.SchedulerImpl]  Scheduling delayed action: com.genesyslab.platform.applicationblocks.warmstandby.WarmStandbyService$ReopenTimerTask@1cd427a; delay:10000
{11:05:12; 17:16:52.562} DEBUG [PSDK.Timer    ] [mmons.timer.impl.SchedulerImpl]  Canceling ticket 'com.genesyslab.platform.applicationblocks.warmstandby.WarmStandbyService$ReopenTimerTask@1cd427a'
{11:05:12; 17:16:52.562} DEBUG [PSDK.Timer    ] [ol.runtime.ConnectionProxyImpl]  Setting settings: s{10.101.160.88, 8001}/n: TestClient/r: 20000/sw: 3600
{11:05:12; 17:16:52.562} DEBUG [PSDK.Timer    ] [ocol.runtime.TransitionManager]  Transition from '.StateAbsent@3f58bb proxy: proxy1' to '.StateOpening@da9067 proxy: proxy1
{11:05:12; 17:16:52.562} DEBUG [PSDK.Timer    ] [.protocol.runtime.StateOpening]  Opening connection. Settings: s{10.101.160.88, 8001}/n: TestClient/r: 20000/sw: 3600
{11:05:12; 17:16:52.562} DEBUG [PSDK.Timer    ] [ol.runtime.ConnectionProxyImpl]  Setting connection: tcp://10.101.160.88:8001[Closed]/7
{11:05:12; 17:16:52.562} DEBUG [PSDK.Timer    ] [ection.impl.AbstractConnection]  ConnState transition. 'Closed' -> 'Opening' for 'tcp://10.101.160.88:8001[Opening]/6 - HA
{11:05:12; 17:16:52.562} DEBUG [PSDK.Timer    ] [mux.MultiplexingConnectionImpl]  Opening MuxConnection tcp://10.101.160.88:8001[Closed]/7
{11:05:12; 17:16:52.562} DEBUG [PSDK.Timer    ] [ection.impl.AbstractConnection]  ConnState transition. 'Closed' -> 'Opening' for 'tcp://10.101.160.88:8001[Opening]/7
{11:05:12; 17:16:52.562} DEBUG [PSDK.Timer    ] [mux.MultiplexingConnectionImpl]  Connection sequence initiated for tcp://10.101.160.88:8001[Opening]/7
{11:05:12; 17:16:52.562} DEBUG [Selector#0    ] [ction.impl.mux.SelectorManager]  Registering channel for connect: java.nio.channels.SocketChannel[connection-pending remote=/10.101.160.88:8001]
{11:05:12; 17:16:53.250} DEBUG [Selector#0    ] [ction.impl.mux.SelectorManager]  Processing connection key
{11:05:12; 17:16:53.265} DEBUG [Selector#0    ] [ection.impl.AbstractConnection]  ConnState transition. 'Opening' -> 'Opened' for 'tcp://10.101.160.88:8001[Opened]/7
{11:05:12; 17:16:53.265} DEBUG [Selector#0    ] [ocol.runtime.TransitionManager]  Transition from '.StateOpening@da9067 proxy: proxy1' to '.StateRegistering@17892d5 proxy: proxy1
{11:05:12; 17:16:53.265} DEBUG [Selector#0    ] [col.runtime.TServerConnContext]  Context session id = 0
{11:05:12; 17:16:53.265} DEBUG [Selector#0    ] [ce.protocol.runtime.MessageGun]  Sending registration. SessionId = 0; Settings = s{10.101.160.88, 8001}/n: TestClient/r: 20000/sw: 3600
{11:05:12; 17:16:53.265} DEBUG [Selector#0    ] [ce.protocol.runtime.MessageGun]  Application name: 'TestClient'
{11:05:12; 17:16:53.265} DEBUG [Selector#0    ] [lab.platform.internal.con.data]  bytes written: 62 to 'java.nio.channels.SocketChannel[connected local=/2.0.5.237:2714 remote=/10.101.160.88:8001]
{11:05:12; 17:16:53.937} DEBUG [Selector#0    ] [me.ProtocolMessagePackagerImpl]  New message #95
{11:05:12; 17:16:53.937} DEBUG [Selector#0    ] [ol.runtime.ConnectionProxyImpl]  Proxy got message EventLinkConnected. Processing with  state .StateRegistering@17892d5 proxy: proxy1
{11:05:12; 17:16:53.937} DEBUG [Selector#0    ] [rotocol.runtime.HAMessagesUtil]  Session id = 15,663,107
{11:05:12; 17:16:53.937} DEBUG [Selector#0    ] [rotocol.runtime.HAMessagesUtil]  Checking server role: 'EventLinkConnected' (95) attributes:
AttributeRegistrationCode [int] = 0 [Primary]
AttributeApplicationName [str] = "tserver_smithfield_sec"
AttributeServerStartTime [long] = 5741238021861639547
AttributeSessionID [int] = 15663107
AttributeUserData [bstr] = KVList:
AttributeEventSequenceNumber [long] = 81
TimeStamp:
AttributeTimeinSecs [int] = 1336736814
AttributeTimeinuSecs [int] = 881231
CallHistoryInfo:
LastRemoteParty:
FirstRemoteParty:
{11:05:12; 17:16:53.937} DEBUG [Selector#0    ] [ocol.runtime.TransitionManager]  Transition from '.StateRegistering@17892d5 proxy: proxy1' to '.StatePrimaryConnected@17aaa0e proxy: proxy1
{11:05:12; 17:16:53.937} DEBUG [Selector#0    ] [ol.runtime.ConnectionProxyImpl]  Setting settings: null
{11:05:12; 17:16:53.937} DEBUG [Selector#0    ] [rotocol.runtime.HAMessagesUtil]  Session id = 15,663,107
{11:05:12; 17:16:53.937} DEBUG [Selector#0    ] [col.runtime.TServerConnContext]  Context session id = 15663107
{11:05:12; 17:16:53.937} DEBUG [Selector#0    ] [ocol.runtime.TransitionManager]  Transition from '.StatePrimaryConnected@17aaa0e proxy: proxy1' to '.StatePrimary@95ef17 proxy: proxy1
{11:05:12; 17:16:53.937} DEBUG [Selector#0    ] [ocol.runtime.TransitionManager]  and from '.StateNotAvailable@183da96 proxy: proxy2' to '.StateBackupConnecting@183d59c proxy: proxy2
{11:05:12; 17:16:53.937} INFO  [Selector#0    ] [.protocol.runtime.StatePrimary]  Primary connected
{11:05:12; 17:16:53.937} DEBUG [Selector#0    ] [ce.protocol.runtime.MessageGun]  Stored link 'EventLinkConnected' (95 -> -1)
{11:05:12; 17:16:53.937} DEBUG [Selector#0    ] [.protocol.runtime.HAConnection]  notifying channel handler
{11:05:12; 17:16:53.937} DEBUG [Selector#0    ] [ice.protocol.runtime.TimerUtil]  Can't start timer, no backup settings. Single server mode?
{11:05:12; 17:16:53.937} DEBUG [.defaultInvoker] [mons.broker.EventBrokerService]  Publishing {0} ...'EventLinkConnected' (95) attributes:
AttributeRegistrationCode [int] = 0 [Primary]
AttributeApplicationName [str] = "tserver_smithfield_sec"
AttributeServerStartTime [long] = 5741238021861639547
AttributeSessionID [int] = 15663107
AttributeUserData [bstr] = KVList:
AttributeEventSequenceNumber [long] = 81
TimeStamp:
AttributeTimeinSecs [int] = 1336736814
AttributeTimeinuSecs [int] = 881231
CallHistoryInfo:
LastRemoteParty:
FirstRemoteParty:
{11:05:12; 17:16:53.937} DEBUG [Selector#0    ] [rotocol.runtime.HAMessagesUtil]  Can't create second connection, no settings
{11:05:12; 17:16:53.937} DEBUG [.defaultInvoker] [mons.broker.EventBrokerService]  Notifying 20 subscribers...
{11:05:12; 17:16:53.937} DEBUG [Selector#0    ] [ocol.runtime.TransitionManager]  Transition from '.StateBackupConnecting@183d59c proxy: proxy2' to '.StateNotAvailable@1ad9b0f proxy: proxy2
{11:05:12; 17:16:53.937} DEBUG [.defaultInvoker] [mons.broker.EventBrokerService]  20 subscribers notified
{11:05:12; 17:16:53.937} DEBUG [invoker.default] [ol.runtime.ConnectionProxyImpl]  Writing message in 'proxy1' via '.StatePrimary@95ef17 proxy: proxy1' to 'tcp://10.101.160.88:8001[Opened]/7
{11:05:12; 17:16:53.937} DEBUG [.defaultInvoker] [mons.broker.EventBrokerService]  Publishing {0} is completed.'EventLinkConnected' (95) attributes:
AttributeRegistrationCode [int] = 0 [Primary]
AttributeApplicationName [str] = "tserver_smithfield_sec"
AttributeServerStartTime [long] = 5741238021861639547
AttributeSessionID [int] = 15663107
AttributeUserData [bstr] = KVList:
AttributeEventSequenceNumber [long] = 81
TimeStamp:
AttributeTimeinSecs [int] = 1336736814
AttributeTimeinuSecs [int] = 881231
CallHistoryInfo:
LastRemoteParty:
FirstRemoteParty:
{11:05:12; 17:16:53.937} DEBUG [invoker.default] [ocol.runtime.AbstractConnState]  sending RequestRegisterAddress to tcp://10.101.160.88:8001[Opened]/7
{11:05:12; 17:16:53.937} DEBUG [invoker.default] [ol.runtime.ConnectionProxyImpl]  Writing message in 'proxy2' via '.StateNotAvailable@1ad9b0f proxy: proxy2' to 'null
{11:05:12; 17:16:53.937} DEBUG [Selector#0    ] [lab.platform.internal.con.data]  bytes written: 62 to 'java.nio.channels.SocketChannel[connected local=/2.0.5.237:2714 remote=/10.101.160.88:8001]
{11:05:12; 17:16:54.703} DEBUG [Selector#0    ] [me.ProtocolMessagePackagerImpl]  New message #53
{11:05:12; 17:16:54.718} DEBUG [Selector#0    ] [ol.runtime.ConnectionProxyImpl]  Proxy got message EventRegistered. Processing with  state .StatePrimary@95ef17 proxy: proxy1
{11:05:12; 17:16:54.718} DEBUG [Selector#0    ] [.protocol.runtime.StatePrimary]  Checking message in primary: EventRegistered
{11:05:12; 17:16:54.718} DEBUG [Selector#0    ] [.protocol.runtime.HAConnection]  notifying channel handler
{11:05:12; 17:16:54.718} DEBUG [Selector#0    ] [me.ProtocolMessagePackagerImpl]  New message #148
{11:05:12; 17:16:54.718} DEBUG [.defaultInvoker] [mons.broker.EventBrokerService]  Publishing {0} ...'EventRegistered' (53) attributes:
AttributeExtensions [bstr] = KVList:
'AgentStatus' [int] = 2
'queue-1' [str] = "7245646821"
'AgentStatusTimestamp' [int] = 1336736776
'AgentStatusReliability' [int] = 1
'AgentLoginTimestamp' [int] = 1336736776
'AgentLoginReliability' [int] = 1
'AgentSessionID' [str] = "0055S1NPI4FQP7IT04000VTAES00000C"
'AgentWorkMode' [int] = 2
'mwl' [int] = 0
'fwd' [str] = "off"
'conn-1' [str] = "00ef020a69a16002"
'call-uuid-1' [str] = "0055S1NPI4FQP7IT04000VTAES000005"
'ct-1' [int] = 2
'ps-1' [int] = 12
'party-uuid-1' [str] = "0055S1NPI4FQP7IT04000VTAES000009"
'status' [int] = 1
AttributeAddressType [int] = 2 [Position]
AttributeThisDN [str] = "7245641507"
AttributeReferenceID [int] = 8
AttributeEventSequenceNumber [long] = 82
AttributeAgentID [str] = "7245645626"
TimeStamp:
AttributeTimeinSecs [int] = 1336736815
AttributeTimeinuSecs [int] = 656918
CallHistoryInfo:
LastRemoteParty:
FirstRemoteParty:
{11:05:12; 17:16:54.718} DEBUG [.defaultInvoker] [mons.broker.EventBrokerService]  Notifying 20 subscribers...
{11:05:12; 17:16:54.718} DEBUG [.defaultInvoker] [mons.broker.EventBrokerService]  20 subscribers notified
{11:05:12; 17:16:54.718} DEBUG [.defaultInvoker] [mons.broker.EventBrokerService]  Publishing {0} is completed.'EventRegistered' (53) attributes:
AttributeExtensions [bstr] = KVList:
'AgentStatus' [int] = 2
'queue-1' [str] = "7245646821"
'AgentStatusTimestamp' [int] = 1336736776
'AgentStatusReliability' [int] = 1
'AgentLoginTimestamp' [int] = 1336736776
'AgentLoginReliability' [int] = 1
'AgentSessionID' [str] = "0055S1NPI4FQP7IT04000VTAES00000C"
'AgentWorkMode' [int] = 2
'mwl' [int] = 0
'fwd' [str] = "off"
'conn-1' [str] = "00ef020a69a16002"
'call-uuid-1' [str] = "0055S1NPI4FQP7IT04000VTAES000005"
'ct-1' [int] = 2
'ps-1' [int] = 12
'party-uuid-1' [str] = "0055S1NPI4FQP7IT04000VTAES000009"
'status' [int] = 1
AttributeAddressType [int] = 2 [Position]
AttributeThisDN [str] = "7245641507"
AttributeReferenceID [int] = 8
AttributeEventSequenceNumber [long] = 82
AttributeAgentID [str] = "7245645626"
TimeStamp:
AttributeTimeinSecs [int] = 1336736815
AttributeTimeinuSecs [int] = 656918
CallHistoryInfo:
LastRemoteParty:
FirstRemoteParty:
{11:05:12; 17:16:54.718} DEBUG [Selector#0    ] [ol.runtime.ConnectionProxyImpl]  Proxy got message EventDNBackInService. Processing with  state .StatePrimary@95ef17 proxy: proxy1
{11:05:12; 17:16:54.718} DEBUG [Selector#0    ] [.protocol.runtime.StatePrimary]  Checking message in primary: EventDNBackInService
{11:05:12; 17:16:54.718} DEBUG [Selector#0    ] [.protocol.runtime.HAConnection]  notifying channel handler
{11:05:12; 17:16:54.718} DEBUG [.defaultInvoker] [mons.broker.EventBrokerService]  Publishing {0} ...'EventDNBackInService' (148) attributes:
AttributeThisDN [str] = "7245641507"
AttributeEventSequenceNumber [long] = 83
TimeStamp:
AttributeTimeinSecs [int] = 1336736815
AttributeTimeinuSecs [int] = 657001
CallHistoryInfo:
LastRemoteParty:
FirstRemoteParty:
{11:05:12; 17:16:54.718} DEBUG [.defaultInvoker] [mons.broker.EventBrokerService]  Notifying 20 subscribers...
{11:05:12; 17:16:54.718} DEBUG [.defaultInvoker] [mons.broker.EventBrokerService]  20 subscribers notified
{11:05:12; 17:16:54.718} DEBUG [.defaultInvoker] [mons.broker.EventBrokerService]  Publishing {0} is completed.'EventDNBackInService' (148) attributes:
AttributeThisDN [str] = "7245641507"
AttributeEventSequenceNumber [long] = 83
TimeStamp:
AttributeTimeinSecs [int] = 1336736815
AttributeTimeinuSecs [int] = 657001
CallHistoryInfo:
LastRemoteParty:
FirstRemoteParty:
{11:05:12; 17:18:26.093} DEBUG [WT-EventQueue-0] [ource.softphone.EventProcessor]  EventProc-Command: End
{11:05:12; 17:20:33.468} DEBUG [WT-EventQueue-0] [m.nisource.softphone.SoftPhone]  EndCall: for Line 0
{11:05:12; 17:20:41.500} DEBUG [WT-EventQueue-0] [m.nisource.softphone.SoftPhone]  Active Line is 0EventEstablished1Idle
{11:05:12; 17:20:41.500} DEBUG [WT-EventQueue-0] [m.nisource.softphone.SoftPhone]  ActiveDTMF Line is: 0
{11:05:12; 17:20:47.593} DEBUG [WT-EventQueue-0] [m.nisource.softphone.SoftPhone]  CurrentState of Call: EventEstablished TeleCallStatus Established
{11:05:12; 17:20:50.046} DEBUG [WT-EventQueue-0] [m.nisource.softphone.SoftPhone]  Executing: END:
{11:05:12; 17:22:00.343} DEBUG [WT-EventQueue-0] [ol.runtime.ConnectionProxyImpl]  Writing message in 'proxy1' via '.StatePrimary@95ef17 proxy: proxy1' to 'tcp://10.101.160.88:8001[Opened]/7
{11:05:12; 17:22:00.343} DEBUG [WT-EventQueue-0] [ocol.runtime.AbstractConnState]  sending RequestReleaseCall to tcp://10.101.160.88:8001[Opened]/7
{11:05:12; 17:22:00.343} DEBUG [WT-EventQueue-0] [ol.runtime.ConnectionProxyImpl]  Writing message in 'proxy2' via '.StateNotAvailable@1ad9b0f proxy: proxy2' to 'null
{11:05:12; 17:22:00.343} DEBUG [Selector#0    ] [lab.platform.internal.con.data]  bytes written: 48 to 'java.nio.channels.SocketChannel[connected local=/2.0.5.237:2714 remote=/10.101.160.88:8001]
{11:05:12; 17:22:01.062} DEBUG [Selector#0    ] [me.ProtocolMessagePackagerImpl]  New message #52
{11:05:12; 17:22:01.078} DEBUG [Selector#0    ] [ol.runtime.ConnectionProxyImpl]  Proxy got message EventError. Processing with  state .StatePrimary@95ef17 proxy: proxy1
{11:05:12; 17:22:01.078} DEBUG [Selector#0    ] [.protocol.runtime.StatePrimary]  Checking message in primary: EventError
{11:05:12; 17:22:01.078} DEBUG [Selector#0    ] [.protocol.runtime.HAConnection]  notifying channel handler
{11:05:12; 17:22:01.078} DEBUG [.defaultInvoker] [mons.broker.EventBrokerService]  Publishing {0} ...'EventError' (52) attributes:
AttributeConnID [long] = 00ab020611a40280
AttributeThisDN [str] = "7245641507"
AttributeReferenceID [int] = 9
AttributeErrorCode [int] = 56
AttributeEventSequenceNumber [long] = 84
TimeStamp:
AttributeTimeinSecs [int] = 1336737122
AttributeTimeinuSecs [int] = 10478
CallHistoryInfo:
LastRemoteParty:
FirstRemoteParty:
{11:05:12; 17:22:01.078} DEBUG [.defaultInvoker] [mons.broker.EventBrokerService]  Notifying 20 subscribers...
{11:05:12; 17:22:01.078} DEBUG [.defaultInvoker] [m.nisource.softphone.SoftPhone]  TeleAddress Event = EventError
{11:05:12; 17:22:01.078} DEBUG [.defaultInvoker] [m.nisource.softphone.SoftPhone]  Error null Code 56 Reasons : null
{11:05:12; 17:22:01.078} DEBUG [.defaultInvoker] [mons.broker.EventBrokerService]  20 subscribers notified
{11:05:12; 17:22:01.078} DEBUG [.defaultInvoker] [mons.broker.EventBrokerService]  Publishing {0} is completed.'EventError' (52) attributes:
AttributeConnID [long] = 00ab020611a40280
AttributeThisDN [str] = "7245641507"
AttributeReferenceID [int] = 9
AttributeErrorCode [int] = 56
AttributeEventSequenceNumber [long] = 84
TimeStamp:
AttributeTimeinSecs [int] = 1336737122
AttributeTimeinuSecs [int] = 10478
CallHistoryInfo:
LastRemoteParty:
FirstRemoteParty:
{11:05:12; 17:44:29.828} DEBUG [WT-EventQueue-0] [ource.softphone.EventProcessor]  Received Windows Event java.awt.event.WindowEvent[WINDOW_CLOSING,opposite=null,oldState=0,newState=0] on frame0
{11:05:12; 17:44:29.828} DEBUG [WT-EventQueue-0] [m.nisource.softphone.SoftPhone]  HandleWindow Cmd windowClosing
{11:05:12; 17:44:31.750} DEBUG [WT-EventQueue-0] [m.nisource.softphone.SoftPhone]  Received Confirmation true
{11:05:12; 17:44:31.750} DEBUG [WT-EventQueue-0] [m.nisource.softphone.SoftPhone]  Exiting SoftPhone at Cmd windowClosing
{11:05:12; 17:44:31.750} DEBUG [WT-EventQueue-0] [ol.runtime.ConnectionProxyImpl]  Writing message in 'proxy1' via '.StatePrimary@95ef17 proxy: proxy1' to 'tcp://10.101.160.88:8001[Opened]/7
{11:05:12; 17:44:31.750} DEBUG [WT-EventQueue-0] [ocol.runtime.AbstractConnState]  sending RequestUnregisterAddress to tcp://10.101.160.88:8001[Opened]/7
{11:05:12; 17:44:31.750} DEBUG [WT-EventQueue-0] [ol.runtime.ConnectionProxyImpl]  Writing message in 'proxy2' via '.StateNotAvailable@1ad9b0f proxy: proxy2' to 'null
{11:05:12; 17:44:31.750} DEBUG [Selector#0    ] [lab.platform.internal.con.data]  bytes written: 44 to 'java.nio.channels.SocketChannel[connected local=/2.0.5.237:2714 remote=/10.101.160.88:8001]
[/code]


Please Help



Offline genesysguru

  • Sr. Member
  • ****
  • Posts: 293
  • Karma: 12
    • Genesys Guru Blog
Hi,

If I remeber correctly you need to perform a QueryDN (or something like that) to get the new connectionId and then use that on the release.

Offline René

  • Administrator
  • Hero Member
  • *****
  • Posts: 1832
  • Karma: 62
Hi,

There is no synchronisation between T-Servers running in warm-standby HA pair so backup T-Server isn't aware of active calls. Information about active call(s) is provided as part of EventRegistered event. If you use connection id listed there then you should be able to release the call.

R.