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