CCM gets timed out in 12 sec and disconnect the call

[raul]

My system are CCM + genesys Tserver.
when a customer Establish a call with an agent,CCM gets timed out in 12 sec and disconnect the call.In the Tserver log,I found error “Cause=CAUSE_RESOURCES_NOT_AVAILABLE/ CiscoCause=CAUSE_RESOURCESNAVAIL” when the problem happened.

Can someone please suggest any way-out or a clue?

Thanks

[René]

Hi,

You wrote that call is disconnected after 12 seconds of being established. It looks to me like a Cisco issue as text "Cause=CAUSE_RESOURCES_NOT_AVAILABLE" comes from JTAPI link.

Have you discussed this with your Cisco engineer?

R.

[raul]

Hi René:
      Thank you for your reply.I have discussed this with my Cisco engineer,he had already checked MOH resources configuration,MRP,GateWay...and so on in CCM and couldn't find anything.We two are very young and lack of experience with this system,can you suggest which configuration we should to check in CCM?

Best Regard

raul

[René]

Raul,

I'm not CCM expert so cannot help you.

Could you post here TServer log snippet showing what is happening before and after mentioned error?

R.

[raul]

Hi René:
Here are Tserver log when the problem happened.Note the key steps below:
15:48:36 before the error,the call has established.
15:48:48 after 12 seconds,error "Type=ConnFailedEvent Cause=CAUSE_RESOURCES_NOT_AVAILABLE" has appeared,and the call disconnected automaticly.
15:49:19-15:49:20 after the error,two ip phone released one after another.

If you want more logs,I can post them here,thank you very much,best regard.

[code]
@15:48:36.9210 [0] 7.5.005.05 distribute_event: message EventEstablished
AttributeEventSequenceNumber 00000000000000af
AttributeTimeinuSecs 921000
AttributeTimeinSecs 1331711316 (15:48:36)
AttributeOtherDN '6055'
AttributeOtherDNRole 1
AttributeThisDNRole 2
AttributeThisDN '2001'
AttributeNetworkPartyRole 2
AttributeNetworkDestDN 'cisco::1101'
AttributeCustomerID 'Resources'
AttributeLastTransferOrigDN '102'
AttributeLastTransferConnID 007402059eab3003
AttributeLastTransferHomeLocation 'TServer_IVR@Switch_GVP'
AttributeFirstTransferOrigDN '102'
AttributeFirstTransferConnID 007402059eab3003
AttributeFirstTransferHomeLocation 'TServer_IVR@Switch_GVP'
AttributeANI '6055'
AttributeDNIS '1111'
AttributeUserData [478] 00 13 00 00..
'RVQID' ''
'RTargetTypeSelected' '2'
'RTargetRuleSelected' ''
'RTargetObjectSelected' 'ChGroup'
'RTargetAgentSelected' '2001'
'RTargetPlaceSelected' 'Place_2001'
'RTenant' 'Resources'
'RStrategyName' 'toChGroup_new'
'CBR-actual_volume' ''
'CBR-Interaction_cost' ''
'CBR-contract_DBIDs' ''
'CBR-IT-path_DBIDs' ''
'RRequestedSkillCombination' ''
'RRequestedSkills'(list)
'RTargetRequested' 'ChGroup'
'CustomerSegment' 'default'
'ServiceType' 'default'
'ServiceObjective' ''
'PegAGChGroup' 1
AttributeCallUUID 'K3GGV3UR7D7I78A21MLTG9J2AG00000K'
AttributeConnID 007402059eab3003
AttributeCallID 16843222
AttributeCallType 2
AttributeCallState 0
AttributeAgentID '2001'
@15:48:36.9210 [ISCC] Debug: Translate: '6055' -> ''; result 1 ()
15:48:36.921 Int 04544 Interaction message "EventEstablished" generated
15:48:36.921 Trc 04542 EventEstablished sent to [2336] (00000005 DesktopToolkitX 10.9.168.85:1789)
15:48:36.921 Trc 04542 EventEstablished sent to [348] (00000002 Stat_Server 10.9.168.85:1192)
@15:48:36.9210 [gctmi] Party [007402059eab3003:6055,s1000c,tUNK,rORG,lEXT] processEstablished
@15:48:36.9210 [gctm] Party [007402059eab3003:6055,s1000c,tUNK,rORG,lEXT] Changing state to c
@15:48:36.9210 [gctm] Call [007402059eab3003/10101d6,sOG,tOG,l2] Changing state to 6
@15:48:36.9210 [gctm] Call [007402059eab3003/10101d6,sES,tOG,l2] Setting timer to ES:100800000mS
@15:48:36.9210 [ISCC] Debug: [connection 011e8ea0] Received from connection [2152]2
@15:48:36.9210 [ISCC] Trace: Received from server TServer_IVR@Switch_GVP/0/2/2: message ISCCEventCallDeleted
ISCCAttributeConnID 007402059eab3003
ISCCAttributeTrackingID 7602191 [0074000f]
@15:48:36.9210 [ISCC] Trace: - tep [007402059eab3003:TServer_IVR@Switch_GVP:007402059eab3003]
@15:48:36.9210 [ISCC] Debug: Party is removed [expected]:
@ c:007402059eab3003,011d9588 @ m:0000000000000000,00000000 p:2 i:010101d6 nw:0000000000000000 t:2
- p:007402059eab3003,011ef150 @ c:007402059eab3003,011d9588 r:1 c----- n:102:TServer_IVR@Switch_GVP
  p:0000000000000000,011e6758 @ c:007402059eab3003,011d9588 r:2 ------ n:2001:
@15:48:48.9370 [((] S 9 'CallEv(2001)=> Type=ConnFailedEvent Cause=CAUSE_RESOURCES_NOT_AVAILABLE CiscoCause=CAUSE_RESOURCESNAVAIL Cid=16843222 MetaCode(true)=META_CALL_PROGRESS Addr=2001'
@15:48:48.9370 [((] S 9 'CallEv(2001)=> Type=CallCtlConnFailedEv Cause=CAUSE_RESOURCES_NOT_AVAILABLE CiscoCause=CAUSE_RESOURCESNAVAIL Cid=16843222 MetaCode(false)=META_CALL_PROGRESS Addr=2001'
@15:48:48.9370 [((] S 9 'CallEv(2001)=> Type=ConnDisconnectedEvent Cause=CAUSE_RESOURCES_NOT_AVAILABLE CiscoCause=CAUSE_RESOURCESNAVAIL Cid=16843222 MetaCode(true)=META_CALL_REMOVING_PARTY Addr=6055'
@15:48:48.9370 [((] S 9 'CallEv(2001)=> Type=CallCtlConnDisconnectedEv Cause=CAUSE_RESOURCES_NOT_AVAILABLE CiscoCause=CAUSE_RESOURCESNAVAIL Cid=16843222 MetaCode(false)=META_CALL_REMOVING_PARTY Addr=6055'
@15:48:48.9370 [((] ISI 5 16843222 '6055' 131
@15:48:48.9370 [tout] Collected jtapi tevent(5:RELEASED)(6055:) (10101d6:83)  (:0).
@15:48:48.9370 [gctmi] TMsg [EventReleased(6055)] distributing to model
@15:48:48.9370 [gctmi] Call [007402059eab3003/10101d6,sES,tES,l2] distributing EventReleased
@15:48:48.9370 [gctmi] Call [007402059eab3003/10101d6,sES,tES,l2] processReleased
@15:48:48.9370 [gctmi] TMsg [EventReleased(6055)] (re)distributing to model in 500mS
@15:48:49.4370 [gctmi] TMsg [EventReleased(6055)] re-distributing to model
@15:48:49.4370 [gctmi] Call [007402059eab3003/10101d6,sES,tES,l2] distributing EventReleased
@15:48:49.4370 [gctmi] Call [007402059eab3003/10101d6,sES,tES,l2] processReleased
@15:48:49.4370 [gctm] Call [007402059eab3003/10101d6,sES,tES,l2] Generating regular release.
@15:48:49.4370 [gctmi] Party [007402059eab3003:6055,sc,tUNK,rORG,lEXT] processReleased
@15:48:49.4370 [gctm] Party [007402059eab3003:6055,sc,tUNK,rORG,lEXT] Changing state to 0
@15:48:49.4370 [gctm] Call [007402059eab3003/10101d6,sES,tES,l1] Setting timer to 1M:30000mS
@15:48:49.4370 [ISCC] Debug: Party removed [ssp view]:
@ c:007402059eab3003,011d9588 @ m:0000000000000000,00000000,0000000000000000 p:2 i:010101d6 nw:00000000:0000000000000000 t:2
- p:011ef150 @ c:007402059eab3003,011d9588 r:1 t:1 s:0 n:6055
  p:011e6758 @ c:007402059eab3003,011d9588 r:2 t:0 s:c n:2001
@15:48:49.4370 [ISCC] Debug: Party removed [finally]:
@ c:007402059eab3003,011d9588 @ m:0000000000000000,00000000 p:1 i:010101d6 nw:0000000000000000 t:2
  p:0000000000000000,011e6758 @ c:007402059eab3003,011d9588 r:2 ------ n:2001:
= p:007402059eab3003,011ef150 @ c:007402059eab3003,011d9588 r:1 c-r--- n:102:
@15:48:49.4370 [ISCC] Debug: Party object is removed: p:007402059eab3003,00000000 n:102:
@15:48:49.4370 [gctm] Party [007402059eab3003:6055,s0,tUNK,rORG,lEXT] deleting.
@15:49:18.9680 [((] S 9 'CallEv(2001)=> Type=TermConnDroppedEv Cause=CAUSE_NORMAL CiscoCause=CAUSE_NORMALCALLCLEARING Cid=16843222 MetaCode(true)=META_CALL_ENDING Addr=2001 Term=SEP005056C00008'
@15:49:18.9680 [((] S 9 'CallEv(2001)=> Type=CallCtlTermConnDroppedEv Cause=CAUSE_NORMAL CiscoCause=CAUSE_NORMALCALLCLEARING Cid=16843222 MetaCode(false)=META_CALL_ENDING Addr=2001 Term=SEP005056C00008'
@15:49:18.9680 [((] ISI 5 16843222 '2001' 100
@15:49:18.9680 [tout] Collected jtapi tevent(5:RELEASED)(2001:) (10101d6:64)  (:0).
@15:49:18.9680 [gctmi] TMsg [EventReleased(2001)] distributing to model
@15:49:18.9680 [gctmi] Call [007402059eab3003/10101d6,sES,t1M,l1] distributing EventReleased
@15:49:18.9680 [gctmi] Call [007402059eab3003/10101d6,sES,t1M,l1] processReleased
@15:49:18.9680 [gctmi] TMsg [EventReleased(2001)] (re)distributing to model in 500mS
@15:49:18.9680 [((] S 9 'CallEv(2001)=> Type=ConnDisconnectedEvent Cause=CAUSE_NORMAL CiscoCause=CAUSE_NORMALCALLCLEARING Cid=16843222 MetaCode(false)=META_CALL_ENDING Addr=2001'
@15:49:18.9680 [((] S 9 'CallEv(2001)=> Type=CallCtlConnDisconnectedEv Cause=CAUSE_NORMAL CiscoCause=CAUSE_NORMALCALLCLEARING Cid=16843222 MetaCode(false)=META_CALL_ENDING Addr=2001'
@15:49:18.9680 [((] ISI 5 16843222 '2001' 100
@15:49:18.9680 [tout] Collected jtapi tevent(5:RELEASED)(2001:) (10101d6:64)  (:0).
@15:49:18.9680 [gctmi] TMsg [EventReleased(2001)] distributing to model
@15:49:18.9680 [gctmi] Call [007402059eab3003/10101d6,sES,t1M,l1] distributing EventReleased
@15:49:18.9680 [gctmi] Call [007402059eab3003/10101d6,sES,t1M,l1] processReleased
@15:49:18.9680 [gctmi] TMsg [EventReleased(2001)] (re)distributing to model in 500mS
@15:49:18.9680 [((] S 9 'CallEv(2001)=> Type=CallInvalidEvent Cause=CAUSE_NORMAL CiscoCause=CAUSE_NORMALCALLCLEARING Cid=16843222 MetaCode(false)=META_CALL_ENDING'
@15:49:18.9680 [((] I 8 16843222
@15:49:18.9680 [tout] Collected jtapi tevent(8:DELETE_CALL)( (10101d6:0)  (:0).
@15:49:18.9680 [gctmi] TMsg [EventCallEnded()] (re)distributing to model in 2000mS
@15:49:18.9680 [((] S 9 'CallEv(2001)=> Type=CallObservationEndedEv Cause=CAUSE_NORMAL CiscoCause=CAUSE_NOERROR Cid=16843222 MetaCode(true)=META_UNKNOWN'
@15:49:19.4680 [gctmi] TMsg [EventReleased(2001)] re-distributing to model
@15:49:19.4680 [gctmi] Call [007402059eab3003/10101d6,sES,t1M,l1] distributing EventReleased
@15:49:19.4680 [gctmi] Call [007402059eab3003/10101d6,sES,t1M,l1] processReleased
@15:49:19.4680 [gctm] Call [007402059eab3003/10101d6,sES,t1M,l1] Generating regular release.
@15:49:19.4680 [gctmi] Party [007402059eab3003:2001,sc,tDN,rDST,lINT] processReleased
@15:49:19.4680 [gctm] Party [007402059eab3003:2001,sc,tDN,rDST,lINT] Changing state to 0
@15:49:19.5310 [tout] CcmAgentParty: Checking if Agent 2001 should go back to Queue
@15:49:19.5310 [0] 7.5.005.05 distribute_event: message EventReleased
AttributeEventSequenceNumber 00000000000000b0
AttributeTimeinuSecs 531000
AttributeTimeinSecs 1331711359 (15:49:19)
AttributeOtherDNRole 1
AttributeOtherDN '6055'
AttributeThisDNRole 2
AttributeThisDN '2001'
AttributeNetworkPartyRole 2
AttributeNetworkDestDN 'cisco::1101'
AttributeCustomerID 'Resources'
AttributeLastTransferOrigDN '102'
AttributeLastTransferConnID 007402059eab3003
AttributeLastTransferHomeLocation 'TServer_IVR@Switch_GVP'
AttributeFirstTransferOrigDN '102'
AttributeFirstTransferConnID 007402059eab3003
AttributeFirstTransferHomeLocation 'TServer_IVR@Switch_GVP'
AttributeANI '6055'
AttributeDNIS '1111'
AttributeUserData [478] 00 13 00 00..
'RVQID' ''
'RTargetTypeSelected' '2'
'RTargetRuleSelected' ''
'RTargetObjectSelected' 'ChGroup'
'RTargetAgentSelected' '2001'
'RTargetPlaceSelected' 'Place_2001'
'RTenant' 'Resources'
'RStrategyName' 'toChGroup_new'
'CBR-actual_volume' ''
'CBR-Interaction_cost' ''
'CBR-contract_DBIDs' ''
'CBR-IT-path_DBIDs' ''
'RRequestedSkillCombination' ''
'RRequestedSkills'(list)
'RTargetRequested' 'ChGroup'
'CustomerSegment' 'default'
'ServiceType' 'default'
'ServiceObjective' ''
'PegAGChGroup' 1
AttributeCallUUID 'K3GGV3UR7D7I78A21MLTG9J2AG00000K'
AttributeConnID 007402059eab3003
AttributeCallID 16843222
AttributeCallType 2
AttributeCallState 0
AttributeAgentID '2001'
@15:49:19.5310 [ISCC] Debug: Translate: '6055' -> ''; result 1 ()
15:49:19.531 Int 04544 Interaction message "EventReleased" generated
15:49:19.531 Trc 04542 EventReleased sent to [2336] (00000005 DesktopToolkitX 10.9.168.85:1789)
15:49:19.531 Trc 04542 EventReleased sent to [348] (00000002 Stat_Server 10.9.168.85:1192)
@15:49:19.5310 [gctmi] Address [2001,tDN,sOFFH] processOnHook
@15:49:19.5310 [gctm] Address [2001,tDN,sOFFH] Changing state to 0
@15:49:19.5310 [0] 7.5.005.05 distribute_event: message EventOnHook
AttributeEventSequenceNumber 00000000000000b1
AttributeCustomerID 'Resources'
AttributeTimeinuSecs 531000
AttributeTimeinSecs 1331711359 (15:49:19)
AttributeThisDN '2001'
@15:49:19.5310 [ISCC] Debug: Translate: '' -> ''; result 1 ()
15:49:19.531 Int 04544 Interaction message "EventOnHook" generated
15:49:19.531 Trc 04542 EventOnHook sent to [2336] (00000005 DesktopToolkitX 10.9.168.85:1789)
15:49:19.531 Trc 04542 EventOnHook sent to [348] (00000002 Stat_Server 10.9.168.85:1192)
@15:49:19.5310 [gctm] Call [007402059eab3003/10101d6,sES,t1M,l0] Setting timer to 0P:2000mS
@15:49:19.5310 [tout] CcmAgentAddress 2001 - Display phone data.
@15:49:19.5310 [tout] Party [007402059eab3003:2001,s0,tDN,rDST,lINT] (CcmIntParty deleted)
@15:49:19.5310 [ISCC] Debug: Party removed [ssp view]:
@ c:007402059eab3003,011d9588 @ m:0000000000000000,00000000,0000000000000000 p:1 i:010101d6 nw:00000000:0000000000000000 t:2
- p:011e6758 @ c:007402059eab3003,011d9588 r:2 t:0 s:0 n:2001
@15:49:19.5310 [ISCC] Debug: Party removed:
@ c:007402059eab3003,011d9588 @ m:0000000000000000,00000000 p:1 i:010101d6 nw:0000000000000000 t:2
- p:0000000000000000,011e6758 @ c:007402059eab3003,011d9588 r:2 ------ n:2001:
@15:49:19.5310 [ISCC] Debug: Party object is removed: p:0000000000000000,00000000 n:2001:
@15:49:19.5310 [gctm] Party [007402059eab3003:2001,s0,tDN,rDST,lINT] deleting.
@15:49:20.9680 [gctmi] TMsg [EventCallEnded()] distributing to model
@15:49:20.9680 [gctmi] Call [007402059eab3003/10101d6,sES,t0P,l0] distributing EventCallEnded
@15:49:20.9680 [gctmi] Call [007402059eab3003/10101d6,sES,t0P,l0] processCallEnded
@15:49:20.9680 [tout] Call [007402059eab3003/10101d6,sES,t0P,l0] (~CcmCall)
@15:49:20.9680 [0] 7.5.005.05 distribute_event: message EventReleased
AttributeEventSequenceNumber 00000000000000b2
AttributeTimeinuSecs 968000
AttributeTimeinSecs 1331711360 (15:49:20)
AttributeNetworkPartyRole 2
AttributeNetworkDestDN 'cisco::1101'
AttributeCustomerID 'Resources'
AttributeLastTransferOrigDN '102'
AttributeLastTransferConnID 007402059eab3003
AttributeLastTransferHomeLocation 'TServer_IVR@Switch_GVP'
AttributeFirstTransferOrigDN '102'
AttributeFirstTransferConnID 007402059eab3003
AttributeFirstTransferHomeLocation 'TServer_IVR@Switch_GVP'
AttributeANI '6055'
AttributeDNIS '1111'
AttributeUserData [478] 00 13 00 00..
'RVQID' ''
'RTargetTypeSelected' '2'
'RTargetRuleSelected' ''
'RTargetObjectSelected' 'ChGroup'
'RTargetAgentSelected' '2001'
'RTargetPlaceSelected' 'Place_2001'
'RTenant' 'Resources'
'RStrategyName' 'toChGroup_new'
'CBR-actual_volume' ''
'CBR-Interaction_cost' ''
'CBR-contract_DBIDs' ''
'CBR-IT-path_DBIDs' ''
'RRequestedSkillCombination' ''
'RRequestedSkills'(list)
'RTargetRequested' 'ChGroup'
'CustomerSegment' 'default'
'ServiceType' 'default'
'ServiceObjective' ''
'PegAGChGroup' 1
AttributeCallUUID 'K3GGV3UR7D7I78A21MLTG9J2AG00000K'
AttributeConnID 007402059eab3003
AttributeCallID 16843222
AttributeCallType 2
AttributeThisDN 'cisco::'
@15:49:20.9680 [ISCC] Debug: Translate: '6055' -> ''; result 1 ()
@15:49:20.9680 [ISCC] Debug: Party object is removed: p:0000000000000000,00000000 n::
@15:49:20.9680 [ISCC] Warning: No call is associated with the event, skipped
@15:49:20.9680 [ISCC] Warning: No call is associated with the event, skipped
@15:49:20.9680 [ISCC] Warning: No call is associated with the event, skipped
@15:49:20.9680 [ISCC] Warning: No call is associated with the event, skipped
15:49:20.968 Int 04544 Interaction message "EventReleased" generated
15:49:20.968 Trc 04542 EventReleased sent to [348] (00000002 Stat_Server 10.9.168.85:1192)
@15:49:20.9680 [ISCC] Debug: Call destroyed:
- c:007402059eab3003,011d9588 @ m:0000000000000000,00000000 p:0 i:010101d6 nw:0000000000000000 t:2
@15:49:20.9680 [ISCC] Debug: Call object is removed: c:007402059eab3003,00000000
@15:49:20.9680 {tscp.call {destructed} {uuid K3GGV3UR7D7I78A21MLTG9J2AG00000K} {connection-id 007402059eab3003} {call-id 16843222}}
@15:49:20.9680 [gctm] Call [007402059eab3003/10101d6,sES,t0P,l0] deleting.
[/code]

[luckikong]

[quote author=raul link=topic=7001.msg30358#msg30358 date=1331712174]
Hi René:
Here are Tserver log when the problem happened.Note the key steps below:
15:48:36 before the error,the call has established.
15:48:48 after 12 seconds,error "Type=ConnFailedEvent Cause=CAUSE_RESOURCES_NOT_AVAILABLE" has appeared,and the call disconnected automaticly.
15:49:19-15:49:20 after the error,two ip phone released one after another.

If you want more logs,I can post them here,thank you very much,best regard.
[/quote]

Well, you show us the details just want to slove the problem or you want to teach us how we can avoid the error?