Hi

I'm testing Avaya out of the box CTI callback assist feature using CTICustomer and CTIAgent. Now I can able to make callback schedule by CTICustomer even Request ID is null. But when callback call is route to CTIAgent, there's no Request ID so call not dial out.

Please see the below for CTICustomer and CTIAgent application trace log. Please help advice where need to check about Callback Request ID.

Thanks,
David

CTICustomer Log
2014-09-25 18:21:30.616 GMT+0000 DEBUG - 3A0C0AB6713E99A4622E0467AE7AF678:/CBACTICustomer : >>>>> Build and Send Callback Request Starts
2014-09-25 18:21:30.617 GMT+0000 DEBUG - 3A0C0AB6713E99A4622E0467AE7AF678:/CBACTICustomer : >>>>> Request CallbackConfigId: 1
2014-09-25 18:21:30.617 GMT+0000 DEBUG - 3A0C0AB6713E99A4622E0467AE7AF678:/CBACTICustomer : >>>>> Request CurrentStatus: CREATED(0)
2014-09-25 18:21:30.617 GMT+0000 DEBUG - 3A0C0AB6713E99A4622E0467AE7AF678:/CBACTICustomer : >>>>> Request PhoneNumber: XXXXXXXXXX
2014-09-25 18:21:30.617 GMT+0000 DEBUG - 3A0C0AB6713E99A4622E0467AE7AF678:/CBACTICustomer : >>>>> Request RetryNumber: 0
2014-09-25 18:21:30.617 GMT+0000 DEBUG - 3A0C0AB6713E99A4622E0467AE7AF678:/CBACTICustomer : >>>>> Request CallTraces: null
2014-09-25 18:21:30.617 GMT+0000 DEBUG - 3A0C0AB6713E99A4622E0467AE7AF678:/CBACTICustomer : >>>>> Request CurrentStatusTime: Thu Sep 25 18:21:30 UTC 2014
2014-09-25 18:21:30.617 GMT+0000 DEBUG - 3A0C0AB6713E99A4622E0467AE7AF678:/CBACTICustomer : >>>>> Request Id: null
2014-09-25 18:21:30.617 GMT+0000 DEBUG - 3A0C0AB6713E99A4622E0467AE7AF678:/CBACTICustomer : >>>>> Request ScheduledDateTime: null
2014-09-25 18:21:30.617 GMT+0000 DEBUG - 3A0C0AB6713E99A4622E0467AE7AF678:/CBACTICustomer : >>>>> Request UserRequestTime: Thu Sep 25 18:21:30 UTC 2014
2014-09-25 18:21:30.617 GMT+0000 DEBUG - 3A0C0AB6713E99A4622E0467AE7AF678:/CBACTICustomer : >>>>> DTMF ANSWER Value: 3472171136
2014-09-25 18:21:30.617 GMT+0000 DEBUG - 3A0C0AB6713E99A4622E0467AE7AF678:/CBACTICustomer : >>>>> DTMF ANSWER Order: 0
2014-09-25 18:21:30.627 GMT+0000 DEBUG - 3A0C0AB6713E99A4622E0467AE7AF678:/CBACTICustomer : >>>>> Error: false
2014-09-25 18:21:30.627 GMT+0000 DEBUG - 3A0C0AB6713E99A4622E0467AE7AF678:/CBACTICustomer : >>>>> Build and Send Callback Request Ends
2014-09-25 18:21:30.627 GMT+0000 INFO - 3A0C0AB6713E99A4622E0467AE7AF678:/CBACTICustomer : [condition1] Expression [flags:error] Is True
2014-09-25 18:21:30.627 GMT+0000 INFO - 3A0C0AB6713E99A4622E0467AE7AF678:/CBACTICustomer : Using SCESession 3A0C0AB6713E99A4622E0467AE7AF678:/CBACTICustomer servlet : exit

CTIAgent Logs
2014-09-25 18:15:34.536 GMT+0000 INFO - BAFDCF68F7A8B91A90536377E14ED064:/CBACTIAgent : Using SCESession BAFDCF68F7A8B91A90536377E14ED064:/CBACTIAgent servlet : getCTICallInfo
2014-09-25 18:15:34.536 GMT+0000 INFO - BAFDCF68F7A8B91A90536377E14ED064:/CBACTIAgent : >>>>> Get Platform and CallInfo Starts
2014-09-25 18:15:34.536 GMT+0000 INFO - BAFDCF68F7A8B91A90536377E14ED064:/CBACTIAgent : >>>>> DNIS: Channel number or extension = 6426
2014-09-25 18:15:34.544 GMT+0000 INFO - BAFDCF68F7A8B91A90536377E14ED064:/CBACTIAgent : >>>>> Callinfo ANI: 6444
2014-09-25 18:15:34.544 GMT+0000 INFO - BAFDCF68F7A8B91A90536377E14ED064:/CBACTIAgent : >>>>> Callinfo DNIS: 7852
2014-09-25 18:15:34.544 GMT+0000 INFO - BAFDCF68F7A8B91A90536377E14ED064:/CBACTIAgent : >>>>> Callinfo EXTENSION: 6426
2014-09-25 18:15:34.544 GMT+0000 INFO - BAFDCF68F7A8B91A90536377E14ED064:/CBACTIAgent : >>>>> Callinfo UUI length: 20
2014-09-25 18:15:34.544 GMT+0000 INFO - BAFDCF68F7A8B91A90536377E14ED064:/CBACTIAgent : >>>>> Callinfo UUI UTF-8: 00001137931411661885
2014-09-25 18:15:34.544 GMT+0000 INFO - BAFDCF68F7A8B91A90536377E14ED064:/CBACTIAgent : >>>>> Callinfo UCID: 00001150851411668932
2014-09-25 18:15:34.544 GMT+0000 INFO - BAFDCF68F7A8B91A90536377E14ED064:/CBACTIAgent : >>>>> Error Found? false
2014-09-25 18:15:34.544 GMT+0000 INFO - BAFDCF68F7A8B91A90536377E14ED064:/CBACTIAgent : >>>>> Get Platform and CallInfo Ends
2014-09-25 18:15:34.544 GMT+0000 INFO - BAFDCF68F7A8B91A90536377E14ED064:/CBACTIAgent : Using SCESession BAFDCF68F7A8B91A90536377E14ED064:/CBACTIAgent servlet : exit
2014-09-25 18:15:34.545 GMT+0000 DEBUG - BAFDCF68F7A8B91A90536377E14ED064:/CBACTIAgent : *** Reply for [/CBACTICallInfoModule/exit] ***
2014-09-25 18:15:34.545 GMT+0000 DEBUG - BAFDCF68F7A8B91A90536377E14ED064:/CBACTIAgent : 0:<?xml version="1.0" encoding="UTF-8"?>
1:<vxml version="2.1" xmlns="http://www.w3.org/2001/vxml" xml:lang="en-US">
2:<meta name="author" content="Avaya Aura Orchestration Designer"/>
3:<meta name="runtime-version" content="06.00.10.02"/>
4:<meta name="runtimecommon-version" content="06.00.10.02"/>
5:<meta name="copyright" content="Copyright (c) 2002-2011, Avaya"/>
6:<form id="exit">
7:<block>
8:<var name="error" expr="'false'"/>
9:<return namelist="error"/>
10:</block>
11:</form>
12:</vxml>
13:

2014-09-25 18:15:34.548 GMT+0000 INFO - BAFDCF68F7A8B91A90536377E14ED064:/CBACTIAgent : Using SCESession BAFDCF68F7A8B91A90536377E14ED064:/CBACTIAgent servlet : checkCallInfoOutput
2014-09-25 18:15:34.548 GMT+0000 INFO - BAFDCF68F7A8B91A90536377E14ED064:/CBACTIAgent : ** Popped Stack Frame [/CBACTICallInfoModule]
2014-09-25 18:15:34.548 GMT+0000 INFO - BAFDCF68F7A8B91A90536377E14ED064:/CBACTIAgent : Storing :callInfoModule___error to complex: callInfoModule:error as [false]
2014-09-25 18:15:34.548 GMT+0000 INFO - BAFDCF68F7A8B91A90536377E14ED064:/CBACTIAgent : session id:mppsvr002-2014268181534-16 | CBACTIAgent:checkCallInfoOutput | >>>>> | callInfoModule:error : false
2014-09-25 18:15:34.548 GMT+0000 INFO - BAFDCF68F7A8B91A90536377E14ED064:/CBACTIAgent : [condition1] Expression [callInfoModule:error] Is True
2014-09-25 18:15:34.548 GMT+0000 INFO - BAFDCF68F7A8B91A90536377E14ED064:/CBACTIAgent : Using SCESession BAFDCF68F7A8B91A90536377E14ED064:/CBACTIAgent servlet : getConfigRequest
2014-09-25 18:15:34.548 GMT+0000 INFO - BAFDCF68F7A8B91A90536377E14ED064:/CBACTIAgent : CallInfo CallInfo[dnis=7852;extension=6426;ucid=00001150851411668932;ani=6444;uuiAscii=true;uui=00001137931411661885;]
2014-09-25 18:15:34.548 GMT+0000 DEBUG - BAFDCF68F7A8B91A90536377E14ED064:/CBACTIAgent : >>>>> Get CallbackRequest and Configuration Starts
2014-09-25 18:15:34.548 GMT+0000 DEBUG - BAFDCF68F7A8B91A90536377E14ED064:/CBACTIAgent : >>>>> UUI: 00001137931411661885
2014-09-25 18:15:34.550 GMT+0000 ERROR - BAFDCF68F7A8B91A90536377E14ED064:/CBACTIAgent : >>>>> Cannot obtain callback request with id: 00001137931411661885
2014-09-25 18:15:34.550 GMT+0000 INFO - BAFDCF68F7A8B91A90536377E14ED064:/CBACTIAgent : [condition1] Expression [ERROR:business_error] Is True
2014-09-25 18:15:34.550 GMT+0000 INFO - BAFDCF68F7A8B91A90536377E14ED064:/CBACTIAgent : Using SCESession BAFDCF68F7A8B91A90536377E14ED064:/CBACTIAgent servlet : throw_GoodbyeEvent
2014-09-25 18:15:34.552 GMT+0000 DEBUG - BAFDCF68F7A8B91A90536377E14ED064:/CBACTIAgent : *** Reply for [/CBACTIAgent/throw_GoodbyeEvent] ***

Is this using the AES Connector? Can you show the AESC log for the call?

Hi

Thanks for your reply.

Yes we are using AES Connector. Actually I'm not AES engineer so could you provide how to get AESC log.

Thanks,
David

Assuming Tomcat, but if you are on a different appserver, it will be a similar local path.
<tomcat>/webapps/aesconnector/data/log/trace.log

It would be best to delete the log and run one test call so the log won't be too big.

Hi,

Attached are AES Connector log and CBACTICustomer log.

The session Id is 721C80EE05EDEDE55DE56914702DB9BF

Please get back to me your find. Thanks

Thanks,
David

The logs are not in sync. I don't see the error you are referring to.

I did pick one call out of the AES log and it looks like it transfers fine. For some reason the app is trying to put the call on hold AFTER it transfers which is not correct. However, that shouldn't affect the transfer because the call is already gone, but may affect the app.

27/09/2014 15:29:21:473 DEBUG - Transfer.doMerge:6401 found held call 210
27/09/2014 15:29:21:473 DEBUG - Transfer.doMerge:6401 found active call 214
27/09/2014 15:29:21:473 DEBUG - Transfer.doMerge:6401 about to transfer the call
27/09/2014 15:29:21:554 DEBUG - Transfer.doMerge:6401 Updated call info to state:transferred
27/09/2014 15:29:21:604 DEBUG - Hold.doHold:6401 putting on hold ext:6401
27/09/2014 15:29:21:605 ERROR - Hold.doHold 6401: error:Hold.doHold:The platform extension no longer has connections to this call - 210; it could be that the extension has been disconnected from this call

Is it possible to delete both logs and run one call to reproduce the error and make sure logs are in sync? Point out what you are seeing for that call because the transfer appears fine from the log I saw.

Hi

I attached the logs and please let me know if any error. Currently in OD application, I use Blind Call (AES) to transfer the VDN 7851 which is CBACTICustomer VDN and after transferred make Disconnect (hangup). I don't know where is Hold (AES) logs come from.

The session id is 5E6B39D16AFCC2F5B29739A80519B1D0

Thanks,
David

The call transfers fine from the blind call command. There definitely is a hold command being sent across to the app after the transfer, but that won't mess up your transfer, just will give you application errors. You do not need to do a disconnect after a transfer. You should review the app and see what it does after the transfer. From the logs, I don't see anything wrong with this application.

29/09/2014 15:33:09:966 DEBUG - 5E6B39D16AFCC2F5B29739A80519B1D0:/ScriptProV1 : CTICommand.setCallInfoVariableValues: State transferred
29/09/2014 15:33:09:968 DEBUG - 5E6B39D16AFCC2F5B29739A80519B1D0:/ScriptProV1 : CTICommand.execute: encrypted value is HeOhNXdyzSKLXU4S2Gp+n0rg5s413ONJU3SENtSUD4Q=
29/09/2014 15:33:09:968 DEBUG - 5E6B39D16AFCC2F5B29739A80519B1D0:/ScriptProV1 : VariableUtil.getVariableValue: Variable value is 12424
29/09/2014 15:33:09:968 DEBUG - 5E6B39D16AFCC2F5B29739A80519B1D0:/ScriptProV1 : CTICommand.execute: request to manager is http://192.168.155.140:8080/aesconnector/Hold?callid%3D12424%26extension%3D6401&k=HeOhNXdyzSKLXU4S2Gp%2Bn0rg5s413ONJU3SENtSUD4Q%3D
29/09/2014 15:33:09:968 DEBUG - 5E6B39D16AFCC2F5B29739A80519B1D0:/ScriptProV1 : CTICommand.execute: setting session cookie to 5E6B39D16AFCC2F5B29739A80519B1D0:/ScriptProV1
29/09/2014 15:33:09:972 DEBUG - 5E6B39D16AFCC2F5B29739A80519B1D0:/ScriptProV1 : CTICommand.execute: callinfo from Manager is error:java.lang.Exception: Hold.doHold:The platform extension no longer has connections to this call - 12424; it could be that the extension has been disconnected from this call
29/09/2014 15:33:09:978 INFO - 5E6B39D16AFCC2F5B29739A80519B1D0:/ScriptProV1 : Capturing exception [com.avaya.sce.runtimecommon.SCERuntimeException]. Message [java.lang.Exception: Hold.doHold:The platform extension no longer has connections to this call - 12424; it could be that the extension has been disconnected from this call]
29/09/2014 15:33:09:979 DEBUG - 5E6B39D16AFCC2F5B29739A80519B1D0:/ScriptProV1 : session id:mppsvr001-2014272203210-19 | ScriptProV1:CBA_CTITransfer | Could not place caller on hold
29/09/2014 15:33:09:981 INFO - 5E6B39D16AFCC2F5B29739A80519B1D0:/ScriptProV1 : Using SCESession 5E6B39D16AFCC2F5B29739A80519B1D0:/ScriptProV1 servlet : hangup

Hi

Thanks for your time to help. Now the Callback Assist Agent able to dial out. Actually we managed to fix the setting in CM.

Thanks,
David

Please post your solution (the specific change you made in CM) for the benefit of others.