[cisco-voip] SCCP/SDL trace question re:transfer

Tue Sep 2 13:16:29 EDT 2014

Interesting, thanks Brian. I was reading through the trace in translatorX,
I guess I should have been searching through the raw files also for errors.

So it looks like if this BugID is the issue, we have a few options..

Possibly convert our gateways to H.323 and use the "voice call send-alert"
as Brian shows
Upgrade to one of the "Fixed-in" releases for 9.1
Possibly have Unity or UCCX handle the call as a supervised transfer
instead of blind (possibly a short term workaround fix)

On Tue, Sep 2, 2014 at 12:42 PM, Brian Meade <bmeade90 at vt.edu> wrote:

> Looks like this might be it-
> https://tools.cisco.com/bugsearch/bug/CSCun15967
>
> The carrier is sending an incoming progress message with a progress
> indicator instead of an alerting.  This does result in early media being
> set up similar to what is seen in the bug.
>
> If you switch the gateway to H.323 or SIP, we could use "voice call
> send-alert" on the dial-peers to convert the progress message with a
> progress indicator into an actual alerting message which will probably
> prevent this bug.
>
> Brian
>
>
> On Tue, Sep 2, 2014 at 12:30 PM, Brian Meade <bmeade90 at vt.edu> wrote:
>
>> Ed sent me his traces and I took a look.  The transfer is failing due to
>> the TWaitResponse timer kicking off.  It looks like that hits after 12
>> seconds.
>>
>> 10645759.000 |22:58:50.306 |SdlSig   |TWaitResponse
>>    |getting_secondary_call_info    |Transferring(3,100,51,311897)
>>  |SdlTimerService(3,100,3,1)
>> |2,100,13,430037.412135^10.192.2.164^CUCxnUM1-VI78
>> |[R:H-H:0,N:0,L:0,V:0,Z:0,D:0]
>> 10645759.001 |22:58:50.306 |AppInfo
>>  |Transferring::getting_secondary_call_info_TWaitResponse - ERROR time out
>> on waiting for correct transfer destination
>> 10645759.002 |22:58:50.306 |AppInfo  |Transferring -
>> handleTransferErrorPreStart, ERROR fid=[4], Retaining Calls, xferring[3,
>> 58262431], xferred[3, 58262428]. infoCause=63, clearCause=41
>>
>>
>>
>> In the working call scenario, the destination answers the call within 12
>> seconds (10 seconds until Connect).  In the failed scenario, we see the
>> call isn't answered until the 13 second mark.
>>
>> Does anyone know what the TWaitResponse timer corresponds to?
>>
>>
>> On Tue, Sep 2, 2014 at 12:04 PM, Daniel Pagan <dpagan at fidelus.com> wrote:
>>
>>>  Ed:
>>>
>>>
>>>
>>> Detailed CCM traces should suffice. If it indeed was a 12 second media
>>> exchange timeout, you should notice a missing SCCP or MGCP transaction
>>> after receiving the ISDN Call Proceeding event. I would check to make sure
>>> I see the OpenReceiveChannel, StartMediaTransmission, and
>>> OpenReceiveChannelACK on the SCCP call-leg followed by a MDCX with SDP to
>>> the MGCP gateway and a 200 response – all immediately after ISDN Call
>>> Proceeding comes in. If you notice one of these missing then it’s likely an
>>> MX timeout issue. I’ve recently seen an issue where StationD doesn’t ACK an
>>> OpenReceiveChannel signal, resulting in a MX timeout. Doubt it’s related to
>>> this problem though… my issue was related to CTI ports.
>>>
>>>
>>>
>>> - Dan
>>>
>>>
>>>
>>> *From:* Ed Leatherman [mailto:ealeatherman at gmail.com]
>>> *Sent:* Tuesday, September 02, 2014 10:36 AM
>>> *To:* Daniel Pagan
>>> *Cc:* Sreekanth Narayanan; Mike Nickolich; Cisco VOIP
>>>
>>> *Subject:* Re: [cisco-voip] SCCP/SDL trace question re:transfer
>>>
>>>
>>>
>>> Dan,
>>>
>>>
>>>
>>> I'm not seeing a MXTimeout, however the "Cannot Complete Transfer" is 12
>>> seconds after the ISDN Proceeding. Any special trace settings necessary to
>>> see that message?
>>>
>>>
>>>
>>> 22:58:38.411 |AppInfo  |In  Message -- PriCallProceedingMsg -- Protocol=
>>> PriNi2Protocol
>>>
>>> ..
>>>
>>> 22:58:50.310 |AppInfo  |StationD:    (0331221) DisplayNotify
>>> timeOutValue=15 notify='Cannot Complete Transfer' content='Cannot Complete
>>> Transfer' ver=12.
>>>
>>>
>>>
>>>
>>>
>>>
>>>
>>>
>>>
>>> On Tue, Sep 2, 2014 at 9:34 AM, Daniel Pagan <dpagan at fidelus.com> wrote:
>>>
>>>  Ed:
>>>
>>>
>>>
>>> As a test, are you able to recreate the issue when PSTN leg doesn’t
>>> answer for 12 seconds after the transfer attempt? I ask because, based on
>>> the timestamps below, it seems the media exchange timer might be expiring.
>>> If you still have SDL traces, you can search for “MXTimeout”. If you find
>>> one, you should be able to backtrack 12 seconds and find the ISDN Call
>>> Proceeding message that triggers CUCM’s attempt at connecting media between
>>> the two call-legs.
>>>
>>>
>>>
>>> - Dan
>>>
>>>
>>>
>>>
>>>
>>> *From:* cisco-voip [mailto:cisco-voip-bounces at puck.nether.net] *On
>>> Behalf Of *Sreekanth Narayanan
>>> *Sent:* Tuesday, September 02, 2014 2:22 AM
>>> *To:* Ed Leatherman
>>> *Cc:* Mike Nickolich; Cisco VOIP
>>> *Subject:* Re: [cisco-voip] SCCP/SDL trace question re:transfer
>>>
>>>
>>>
>>> Hi Ed,
>>>
>>>
>>>
>>> If the Unity is sending the 2nd transfer command as soon as the initial
>>> call setup begins, it looks more like a blind transfer. The other transfer
>>> type 'Supervise Transfer' is the consult transfer. Have you tried to do
>>> blind transfers from SCCP phones?
>>>
>>>
>>>
>>> As per the RTS description, it's the responsibility of the CUCM to
>>> handle the call if the target of the transfer is busy or doesn't answer.
>>>
>>>    - Release to Switch—Unity Connection puts the caller on hold, dials
>>>    the extension, and releases the call to the phone system. When the line is
>>>    busy or is not answered, the phone system—not Unity Connection—forwards the
>>>    call to the user or handler greeting. This transfer type allows Unity
>>>    Connection to process incoming calls more quickly. Use Release to Switch
>>>    only when call forwarding is enabled on the phone system.
>>>
>>>
>>>
>>> Thanks
>>>
>>> Sreekanth
>>>
>>>
>>>
>>>
>>>
>>> On 1 September 2014 19:29, Ed Leatherman <ealeatherman at gmail.com> wrote:
>>>
>>>  Hi Sreekanth,
>>>
>>>
>>>
>>> The problem is inconsistent, but definitely more than say 20%. Load on
>>> our systems doesn't appear to be an issue, we did testing late at
>>> night/after hours and regular call volume is very low then. We were able to
>>> duplicate the issue just with cell phones as the target, so it seems the
>>> problem is not just the answering service not picking up; not had a problem
>>> where direct calls weren't answered promptly.
>>>
>>>
>>>
>>> In looking through the trace files, it seems like Unity does a consult
>>> transfer even when set to "Release to switch", its just sending the 2nd
>>> transfer command as soon as the initial call setup starts - IIRC it was
>>> doing it right after we got "PROCEEDING" from PSTN.
>>>
>>>
>>>
>>> I did check out the T301 timer in CUCM but its still set to 3 minutes -
>>> so we're not hitting that one at least.
>>>
>>>
>>>
>>> Your idea of reproducing the issue with a consultative transfer from a
>>> phone is a good one, we'll give that a try.
>>>
>>>
>>>
>>> For now we just have their line directly forwarded after hours manually
>>> and skipping Unity completely and it works. They pay per call to the
>>> answering service though so they really want the front end IVR to pick up
>>> first. It is a suicide prevention hotline and they are very sensitive to us
>>> throwing solutions at it until something works - I'll have to at least pin
>>> down the part that is failing before they will accept a workaround. I have
>>> a mini UCCX script setup to do a call redirect to the number, if I can
>>> verify that it is the consultative transfer that is the issue I plan on
>>> just sending the call from Unity to UCCX and letting UCCX get the call
>>> offsite - will probably just move the whole call tree to UCCX for IVR at
>>> that point.
>>>
>>>
>>>
>>>
>>>
>>> Thanks for your ideas!!
>>>
>>>
>>> Ed
>>>
>>>
>>>
>>> On Mon, Sep 1, 2014 at 3:04 AM, Sreekanth Narayanan <sknth.n at gmail.com>
>>> wrote:
>>>
>>>  Hi Ed,
>>>
>>>
>>>
>>> Could it be possible that the answering service does not answer the call
>>> sometimes? This may be causing the timeout.
>>>
>>> From the POV of the CUCM, this is just another regular outgoing call
>>> over PRI starting from a VM port (which acts like an SCCP phone), which
>>> would then do the transfer to the initial caller.
>>>
>>> The transfer type in your case seems to be semi-attended or consult
>>> transfer and not blind. I don't know if this can be changed on Unity.
>>>
>>>
>>>
>>> What is the frequency of this issue? In 10 calls transferred this way,
>>> how many times do you see it?
>>>
>>> Maybe you could try a couple of different tests here to try and isolate
>>> the issue:
>>>
>>> 1. Make direct calls from an IP phone (sccp preferably) to the answering
>>> service and see if the answering service picks the call up every time
>>> without fail.
>>>
>>> 2. Make an inbound call to the CUCM from PSTN, and direct this call to
>>> an sccp phone (this is replacing the Unity), and then do a blind, consult
>>> transfer (2 different tests) to the answering service and see if you can
>>> reproduce the problem.
>>>
>>>
>>>
>>> Thanks
>>> Sreekanth
>>>
>>>
>>>
>>> On 1 September 2014 00:28, Ed Leatherman <ealeatherman at gmail.com> wrote:
>>>
>>>   Hello!
>>>
>>>
>>>
>>> I'm trying to help chase down a intermittent issue where Unity needs to
>>> transfer a caller off-site to an answering service, and sometimes the
>>> transfer doesn't complete and the caller gets left on-hold. I was hoping
>>> someone could explain a message i'm seeing in the traces during a failure.
>>>
>>>
>>>
>>> SCCP integration to unity connection. 9.1 software versions on both CUCM
>>> and Unity. MGCP to PRI gateways. All gateways are set to offnet and service
>>> parameter is configured to allow transfers between offnet to rule that out
>>> as a issue.
>>>
>>>
>>>
>>> On the trace side of things, for the transfer leg on a failure I see:
>>>
>>> 19:55:27.146 : Unity "presses transfer" , dials out the digits
>>>
>>> 19:55:29.853 : Q931 IN from PSTN for the transfer leg,  PROGRESS message
>>>
>>> 19:55:29.855 : CUCM OUT to Unity: Call State Ring out
>>>
>>> *19:55:41.020 : CUCM OUT to Unity: DisplayNotify timeOutValue=15
>>> notify='Cannot Complete Transfer' content='Cannot Complete Transfer' ver=12*
>>>
>>>
>>>
>>> It looks like an abnormal amount of time for the call to connect, is
>>> that a possible reason for the "Cannot Complete Transfer" message? Is the
>>> timeout tweakable someplace?
>>>
>>>
>>>
>>> On successful tries, the transfer leg connects faster (less than 10
>>> seconds). So far we haven't found anything else different on our own; have
>>> a TAC case open on it but getting shuffled between groups now (unity team
>>> wants CUCM team to look at it).
>>>
>>>
>>>
>>> Unity never seems to retrieve the caller from hold or try again,
>>> eventually the caller hangs up (I see the the DISCONNECT message from PSTN)
>>> at which point that call leg gets torn down.
>>>
>>>
>>>
>>> Any ideas much appreciated
>>>
>>>
>>>
>>> Ed
>>>
>>>
>>>
>>>
>>>
>>> _______________________________________________
>>> cisco-voip mailing list
>>> cisco-voip at puck.nether.net
>>> https://puck.nether.net/mailman/listinfo/cisco-voip
>>>
>>>
>>>
>>>
>>>
>>>
>>>
>>> --
>>> Ed Leatherman
>>>
>>>
>>>
>>>
>>>
>>>
>>>
>>> --
>>> Ed Leatherman
>>>
>>> _______________________________________________
>>> cisco-voip mailing list
>>> cisco-voip at puck.nether.net
>>> https://puck.nether.net/mailman/listinfo/cisco-voip
>>>
>>>
>>
>

-- 
Ed Leatherman
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://puck.nether.net/pipermail/cisco-voip/attachments/20140902/4009cfee/attachment.html>