Genesys 7.2 with Nortel Succession 5.5, stuck off-hook ports

[PROFMYSTER]

We've recently upgraded our Opt 61 Meridian to Succession 5.5. which is runnig with Genesys Outbound 7.2 (7.6 T-server, upgraded from 7.5). The dialler is configured with 30 ports that are represented by 30 x 500 sets on an E1 line-side card.

We initially starting getting alot of hung ports, in the off-hook state. We resolved alot of this by setting the LDTD to LTDT (Line Disconnect Tone Allowed) on the cls of the 500 sets.

We now get the odd port through-out the day, sticking off-hook, it clears itself after 30 minutes or we can ring the affected port and this will set the state back to on-hook.

Looking at the CPD and T-server logs it looks as though the CTI traffic at some point just stops with no further events until I see a change state to on-hook event (from the switch), but the T-server responds 'Ignore, call does't exist'. It's like the events are going into a black-hole, or the switch believes one state and the Genesys another.

Anyone experienced sticking off-hook or aware of any issues with Succession 5.5 with Genesys T-server 7.6.

Cheers

[Fra]

Hi,
I have no experience in CPD and Nortel, but my guess is that you miss the hangup\release message: check in your logs if the CPD and the TServer get congruent message (Answer - EventEstablished, Disconnected - EventRelease).
Have you noticed the off-hook state in CCPulse?

[PROFMYSTER]

This is the CPD log, It detects voice and even gets a connection ID, but then we get - 'ReferenceID found: Event 'EventAddressInfo' thereafter. The T-server doesnt show any dialling events etc, gets to the point of creating the connection id and then it all goes dead. All I can see is the corresponding event for the Address Info reference, but no actions are seen in the log until we get the on-hook from thepbx which the t-server then ignores.

        11:50:55.1270 ThID:  5404 ReqID:      19038: call connected: dxxxB5C3

        11:50:55.1270 ThID:  5404 ReqID:      19038: positive voice detection: dxxxB5C3

        11:50:55.1430 ThID:  5404 ReqID:          0: Event 'TCommEvent' received, ThisDN '6010', OtherDN '6010', ANI '6010',ReferenceID '0', ConnectionID '0000000000000000'

        11:50:55.1430 ThID:  5404 ReqID:      19038: DN found: Event 'TCommEvent', ThisDN '6010', OtherDN '6010', ANI '6010',ReferenceID '0', ConnectionID '0000000000000000'

        11:50:55.1430 ThID:  4000 ReqID:      19038: Unsolicited 'TCommEvent' received, 'EventDialing' expected, DN '6010', ThisDN '6010', OtherDN '6010', ANI '6010',ReferenceID '0'

        11:51:35.1520 ThID:  4000 ReqID:      19038: TEvent time-out expired, 'EventEstablished' expected, DN '6010'

        11:51:35.1520 ThID:  4000 ReqID:      19038: out of service counter set to 0: dtiB1T11

        11:51:36.1520 ThID:  4000 ReqID:      19038: T1/E1 data channel released: dtiB1T11

        11:51:36.1520 ThID:  4000 ReqID:      19038: Flushing DN '6010' event queue...

        11:51:36.2150 ThID:  2604 ReqID:          0: Event 'EventAddressInfo' received, ThisDN '6010', OtherDN '', ANI '',ReferenceID '19758', ConnectionID '0000000000000000'

        11:51:36.2150 ThID:  2604 ReqID:      19038: ReferenceID found: Event 'EventAddressInfo', ThisDN '6010', OtherDN '', ANI '',ReferenceID '19758', ConnectionID '0000000000000000'

        11:51:36.7150 ThID:  2604 ReqID:          0: Event 'EventAddressInfo' received, ThisDN '6010', OtherDN '', ANI '',ReferenceID '19759', ConnectionID '0000000000000000'

        11:51:36.7150 ThID:  2604 ReqID:      19038: ReferenceID found: Event 'EventAddressInfo', ThisDN '6010', OtherDN '', ANI '',ReferenceID '19759', ConnectionID '0000000000000000'

        11:51:36.8400 ThID:  2604 ReqID:          0: Event 'EventEstablished' received, ThisDN '6009', OtherDN '1114966', ANI '',ReferenceID '0', ConnectionID '00b2019cbb5186ab'

        11:51:37.2150 ThID:  2604 ReqID:          0: Event 'EventAddressInfo' received, ThisDN '6010', OtherDN '', ANI '',ReferenceID '19761', ConnectionID '0000000000000000'

[Dionysis]

This sounds to me like a bit set issue in your CPD / Dialogic settings that have changed between the old switch and the new.  I have seen similar issues when dialling from a Nortel switch.  Especially if the switch is capable of making a call on a port without the dialogic manually taking it off hook first.

Have you done the checks on the dialogic ports using bitset and IcomNT to monitor the status?

[Fra]

Here you go, CPD waits for an EventEstablished from TServer but the call_wait_original_establish_timeout expires.  Can you attach the TServer logs for the call you have posted here? In the meanwhile I'd check the bitset as suggested.

[PROFMYSTER]

In regard to the bit settings, if these where incorrect would it not affect the same port all the time, where as the problem we get can be against any port at anytime.

This is the T-server log.

Part A is the previous call, Part B shows the ignore on-hook event, Part C shows the corresponding RequestQueryAddress with AttributeReferenceID 19758 on, I've cut this short as it simply keeps doing this for 30 minutes, until Part D kicks in.

[color=red][b]Part A)[/b] [/color]
11:46:28.093 Trc 04541 RequestRegisterAddress received from [576] (00000009 CPD_Server_Digital 172.30.21.27:4271)
message RequestRegisterAddress
AttributeThisDN '6010'
AttributeRegisterMode 0
AttributeControlMode 0
AttributeAddressType 1 (DN)
AttributeReferenceID 19714
(tservice_proc) ControlMode set to 1 for 6010
@11:46:28.0930 [gctmi] Distributing request RequestRegisterAddress
@11:46:28.0930 [tsgctm] Address [6010,tDN,sIDLE] reqRegisterAddress
@11:46:28.0930 [gctmi] request RequestRegisterAddress removed from reqMgr
@11:46:28.0930 [0] 7.6.008.01 send_to_client: message EventRegistered
AttributeEventSequenceNumber 0000000000006b5b
AttributeCustomerID 'Resources'
AttributeTimeinuSecs 93000
AttributeTimeinSecs 1221734788 (11:46:28)
AttributeExtensions [66] 00 03 01 00..
'AgentStatus' -1
'AgentStatusTimestamp' 0
'status' 0
AttributeAddressType 1 (DN)
AttributeThisDN '6010'
AttributeReferenceID 19714
11:46:28.093 Trc 04542 EventRegistered sent to [576] (00000009 CPD_Server_Digital 172.30.21.27:4271)
@11:46:28.0930 [gctmi] Address [6010,tDN,sIDLE] processBackInService
Status Change
This Device TN:4b2
This Device DN:Internal, 6010
This Device Status:Off-Hook
Call ID:4dfb
Enhanced Time Stamp:11:49:23
@11:46:29.4680 [mlink] (processStatusChange)
@11:46:29.4680 [mlink] (processScOffhook)
@11:46:29.4680 [gctmi] TMsg [EventOffHook(6010)] distributing to model
@11:46:29.4680 {tscp.call {constructed} {uuid PH7HTKN8G508D8HD9GHS4NM1J0000529} {connection-id 00b2019cbb51869a} {call-id 19963}}
@11:46:29.4680 Call [00b2019cbb51869a]: urid 000100b2
@11:46:29.4680 [gctm] Call [00b2019cbb51869a/4dfb,sST,tNO,l0] Setting timer to ST:2000mS
@11:46:29.4680 [gctm] Call [00b2019cbb51869a/4dfb,sST,tST,l0] created.
@11:46:29.4680 [gctmi] Call [00b2019cbb51869a/4dfb,sST,tST,l0] distributing EventOffHook
@11:46:29.4680 [gctmi] Call [00b2019cbb51869a/4dfb,sST,tST,l0] processOffHook
@11:46:29.4680 [gctm] Translate Off-Hook to Initiated
@11:46:29.4680 [mlink] Call [00b2019cbb51869a/4dfb,sST,tST,l0] (processInitiated)
@11:46:29.4680 [gctmi] Call [00b2019cbb51869a/4dfb,sST,tST,l0] processInitiated
@11:46:29.4680 [gctmi] Call [00b2019cbb51869a/4dfb,sST,tST,l0] processDialInitiated
@11:46:29.4680 [gctm] Call [00b2019cbb51869a/4dfb,sST,tST,l0] Changing state to 1
@11:46:29.4680 [gctm] Call [00b2019cbb51869a/4dfb,sOG,tST,l0] Setting timer to 0M:7200mS
@11:46:29.4680 [gctm] Call [00b2019cbb51869a/4dfb,sOG,t0M,l0] Setting timer to OG:14400000mS
@11:46:29.4680 [gctm] Party [00b2019cbb51869a:6010,s0,tDN,rORG,lINT] created.
@11:46:29.4680 [gctmi] Party [00b2019cbb51869a:6010,s0,tDN,rORG,lINT] distribute
@11:46:29.4680 [gctmi] Party [00b2019cbb51869a:6010,s0,tDN,rORG,lINT] processInitiated
@11:46:29.4680 [gctmi] Address [6010,tDN,sIDLE] processOffHook
@11:46:29.4680 [gctm] Address [6010,tDN,sIDLE] Changing state to 1
@11:46:29.4680 [0] 7.6.008.01 distribute_event: message EventOffHook
AttributeEventSequenceNumber 0000000000006b5e
AttributeCustomerID 'Resources'
AttributeTimeinuSecs 468000
AttributeTimeinSecs 1221734789 (11:46:29)
AttributeThisDN '6010'
11:46:29.468 Int 04544 Interaction message "EventOffHook" generated
masked for 576 (00000009 CPD_Server_Digital)
11:46:29.468 Trc 04542 EventOffHook sent to [540] (00000003 Stat_Server 172.30.21.32:3881)
11:46:29.468 Trc 04542 EventOffHook sent to [516] (00000002 Stat_Server_Reporting 172.30.21.32:3880)
@11:46:29.4680 [gctm] Party [00b2019cbb51869a:6010,s0,tDN,rORG,lINT] Changing state to 1

[color=red][b]Part B[/b][/color]
@11:47:18.9840 [<<] FF 0A 00 24 0A 00 00 08 0F 00 37 04 04 B2 36 08 00 08 36 30 31 30 38 03 01 96 06 00 00 4D D6 5F 05 0B 32 0B
Status Change
This Device TN:4b2
This Device DN:Internal, 6010
This Device Status:On-Hook
Call ID:4dd6
Enhanced Time Stamp:11:50:11
@11:47:18.9840 [mlink] (processStatusChange)
@11:47:18.9840 [mlink] (processScOnhook)
@11:47:18.9840 [gctmi] TMsg [EventOnHook(6010)] distributing to model
@11:47:18.9840 [gctmi] TMsg [EventOnHook(6010)] Call event ignored, no call exists.

[b][color=red]Part C[/color][/b]
11:47:19.281 Trc 04541 RequestQueryAddress received from [576] (00000009 CPD_Server_Digital 172.30.21.27:4271)
message RequestQueryAddress
AttributeThisDN '6010'
AttributeAddressType 1 (DN)
AttributeAddressInfoType 17 (AddressInfoDNStatus)
AttributeReferenceID 19758
@11:47:19.2810 [0] 7.6.008.01 send_to_client: message EventAddressInfo
AttributeEventSequenceNumber 0000000000006c4b
AttributeCustomerID 'Resources'
AttributeTimeinuSecs 281000
AttributeTimeinSecs 1221734839 (11:47:19)
AttributeReferenceID 19758
AttributeThisDN '6010'
AttributeAddressInfoStatus 0
AttributeExtensions [66] 00 03 01 00..
'AgentStatus' -1
'AgentStatusTimestamp' 0
'status' 1
AttributeAddressInfoType 17 (AddressInfoDNStatus)
11:47:19.281 Trc 04542 EventAddressInfo sent to [576] (00000009 CPD_Server_Digital 172.30.21.27:4271)
11:47:19.781 Trc 04541 RequestQueryAddress received from [576] (00000009 CPD_Server_Digital 172.30.21.27:4271)
message RequestQueryAddress
AttributeThisDN '6010'
AttributeAddressType 1 (DN)
AttributeAddressInfoType 17 (AddressInfoDNStatus)
AttributeReferenceID 19759
@11:47:19.7810 [0] 7.6.008.01 send_to_client: message EventAddressInfo
AttributeEventSequenceNumber 0000000000006c4c
AttributeCustomerID 'Resources'
AttributeTimeinuSecs 781000
AttributeTimeinSecs 1221734839 (11:47:19)
AttributeReferenceID 19759
AttributeThisDN '6010'
AttributeAddressInfoStatus 0
AttributeExtensions [66] 00 03 01 00..
'AgentStatus' -1
'AgentStatusTimestamp' 0
'status' 1
AttributeAddressInfoType 17 (AddressInfoDNStatus)

[color=red][b]Part D[/b][/color]
12:16:29.171 Int 04544 Interaction message "EventAttachedDataChanged" generated
masked for 576 (00000009 CPD_Server_Digital)
12:16:29.171 Trc 04542 EventAttachedDataChanged sent to [540] (00000003 Stat_Server 172.30.21.32:3881)
12:16:29.171 Trc 04542 EventAttachedDataChanged sent to [516] (00000002 Stat_Server_Reporting 172.30.21.32:3880)
@12:16:29.4680 [gctm] Party [00b2019cbb51869a:6010,s1,tDN,rORG,lINT] state timer expired, deleting.
@12:16:29.4680 [gctmi] Party [00b2019cbb51869a:6010,s1,tDN,rORG,lINT] processAbandoned
@12:16:29.4680 [gctm] Party [00b2019cbb51869a:6010,s1,tDN,rORG,lINT] silent abandon from unannounced state
@12:16:29.4680 [gctm] Party [00b2019cbb51869a:6010,s1,tDN,rORG,lINT] Changing state to 0
@12:16:29.4680 [gctmi] Address [6010,tDN,sOFFH] processOnHook
@12:16:29.4680 [gctm] Address [6010,tDN,sOFFH] Changing state to 0
@12:16:29.4680 [0] 7.6.008.01 distribute_event: message EventOnHook
AttributeEventSequenceNumber 0000000000009fbe
AttributeCustomerID 'Resources'
AttributeTimeinuSecs 468000
AttributeTimeinSecs 1221736589 (12:16:29)
AttributeThisDN '6010'
12:16:29.468 Int 04544 Interaction message "EventOnHook" generated
masked for 576 (00000009 CPD_Server_Digital)
12:16:29.468 Trc 04542 EventOnHook sent to [540] (00000003 Stat_Server 172.30.21.32:3881)
12:16:29.468 Trc 04542 EventOnHook sent to [516] (00000002 Stat_Server_Reporting 172.30.21.32:3880)

[Dionysis]

I agree, BitSet seems like a long shot, but I'd check it anyway.  It's always the first check I do on any dialler I build, and I've built quite a lot of them over the years.

This line concerns me a little:
[code]19038: Unsolicited 'TCommEvent' received, 'EventDialing' expected, DN '6010', ThisDN '6010', OtherDN '6010', ANI '6010',ReferenceID '0'[/code]

It could be what is leading to the "ignored" message.

The other thing you can pick up using bitset and IcomNT is if the ports are configured for the wrong resources.  Did you use the wizard to configure the extensions in Config?  Or did you do it manually?  It could be that the extensions and resources are all out by 1 and you are seeing the results on the wrong ports (I've seen this many times when dialogic extensions are configured manually).

[kowari]

Um, CPD is looking ok.
We need to see the TServer logs for a call... it looks like the call is not getting to an agent.

So this could be a config error.  Is OCS configured for one or two step transfer? (Call_transfer_type setting)  If it is one step OCS cant drop the call if there is no agent available, it will just queue - probably confusing the call flow (getting the event ignore garbage)

The OTHER thing (or perhaps as well as) it could be is what Dionysis was getting at, and someone simply plugged the cables in wrong in the back of the dialogic card (dont say it cant happen, it happens ALL the time when people muck about in comms rooms then they dont tell you about it!!) and that was what he was getting at with the bit set thing.

Genesys doco somewhere tells you how to do a simple test (the bit set test) to confirm that the line you tell genesys to pick up is actually the physical line that gets picked up.  Trust me on this one when I say it will save you heart ache and headache if you just confirm each E1 cable is actually where genesys thinks it is

Well, those are the 2 courses of investigation I would go down if I were having this issue.  Hope that helps!