[Freeswitch-users] 10 seconds delay on fallback

Wed Jan 13 19:47:53 PST 2010

Try out a more recent trunk, specifically, svn r16193 had an important fix for signaling handling in bypass and proxy media modes.

Mike

On Jan 13, 2010, at 6:36 PM, Sergey Okhapkin wrote:

> freeswitch at internal> version
> FreeSWITCH Version 1.0.5pre10 (16012M)
> 
> The problem happens with bypass_media=true.
> 
> The lines in log related to the call are (sorry, need to hide IP addresses and 
> numbers):
> 
> recv 1080 bytes from udp/[X.X.X.X]:5060 at 03:27:02.529350:
>   ------------------------------------------------------------------------
>   SIP/2.0 183 Session Progress
> ...
> 2010-01-12 22:27:02.529311 [INFO] sofia.c:509 Update Callee ID to "XXXXX" 
> <sip:XXXXXX at XXXXXX>
> 2010-01-12 22:27:02.529311 [DEBUG] sofia.c:3806 Channel sofia/cwu/XXXXXX at XXXXX 
> entering state [proceeding][183]
> 
> 2010-01-12 22:27:02.529311 [NOTICE] sofia.c:3885 Pre-Answer 2010-01-12 
> 22:27:02.529311 [DEBUG] switch_channel.c:2020 Send signal XXXXXXXXX [BREAK]
> 2010-01-12 22:27:02.529311 [DEBUG] sofia.c:3898 XXXXXXXXXXXXX receive message 
> [PROGRESS]
> 2010-01-12 22:27:02.529311 [INFO] sofia.c:3898 Sending early media
> 2010-01-12 22:27:02.529311 [NOTICE] mod_sofia.c:1765 Pre-Answer XXXXXXXXXXX!
> 2010-01-12 22:27:02.529311 [DEBUG] switch_core_session.c:700 Send signal 
> XXXXXXXXXX [BREAK]
> 2010-01-12 22:27:02.529311 [DEBUG] switch_core_session.c:639 Send signal 
> XXXXXXXXXXXX [BREAK]
>   ------------------------------------------------------------------------
> recv 716 bytes from udp/[XXXXXXXXX]:5060 at 03:27:02.608352:
>   ------------------------------------------------------------------------
>   SIP/2.0 480 Temporarily Unavailable
> ....
> 2010-01-12 22:27:02.611340 [DEBUG] mod_dptools.c:818 XXXXX SET 
> [A2B_id]=[86339421]
> EXECUTE XXXXXXXXXX set(A2B_tp_id_trunk=126)
> 2010-01-12 22:27:02.611340 [DEBUG] mod_dptools.c:818 XXXXXXXXXXXX SET 
> [A2B_tp_id_trunk]=[126]
> EXECUTE XXXXXXXXX sched_hangup(+10800)
> 2010-01-12 22:27:02.611340 [DEBUG] switch_scheduler.c:214 Added task 109951 
> switch_ivr_schedule_hangup (8e75053d-e864-4f34-b768-b41b6839dadd) to run at 
> 1263364022
> EXECUTE XXXXXXXXXXX set(bypass_media=true)
> 2010-01-12 22:27:02.611340 [DEBUG] mod_dptools.c:818 XXXXXXXXX SET 
> [bypass_media]=[true]
> EXECUTE XXXXXXXXX 
> bridge([sip_contact_user=XXXXXX,sip_auth_username=,sip_auth_password=]sofia/cwu/XXXXXXX at XXXXXXX)
> 2010-01-12 22:27:02.612344 [DEBUG] switch_ivr.c:1199 XXXXXXXX receive message 
> [MEDIA]
> 2010-01-12 22:27:02.612344 [DEBUG] switch_core_session.c:639 Send signal 
> XXXXXXXXXXXX [BREAK]
> 
> 10 seconds later:
> 
> 2010-01-12 22:27:12.614323 [NOTICE] switch_channel.c:613 New Channel 
> sofia/cwu/XXXXXXX at XXXXXXX [68cb4360-8da5-49fc-8fbd-f4a4e
> 4351a94]
> 
> 
> 
> 
> 
> On Wednesday 13 January 2010, Michael Collins wrote:
>> Which rev of FreeSWITCH are you running? Also, collect a full debug trace
>> of a working vs. non-working call so that you can compare what's happening.
>> Put those on pastebin so others can have a look.
>> -MC
>> 
>> On Wed, Jan 13, 2010 at 4:46 AM, Sergey Okhapkin
>> 
>> <sos at sokhapkin.dyndns.org>wrote:
>>> To implement fallback to backup PSTN routes and do LCR my dialplan
>>> executes the following commands:
>>> 
>>> set execute_on_answer=set hangup_after_bridge=true
>>> set some custom channel variables
>>> bridge sofia/gateway1/number
>>> set some custom channel variables
>>> bridge sofia/gateway2/number
>>> ....
>>> 
>>> This generally works fine if gateway1 returns SIP error, dialplan sets
>>> channel
>>> variables to another values and calls gateway2 immediately. But if GW1
>>> responds with 183 early media and SIP error after that, bad thing happens
>>> - dialplan continues immediately, sets channel variables, executes bridge
>>> application, but INVITE to GW2 is sent after 10 seconds delay. Caller
>>> gets 10
>>> extra seconds of post dial delay. I suspect the delay happens because of
>>> attempt to read audio frame, switch_ivr_originate() has the following
>>> lines:
>>> 
>>> if (switch_channel_media_ready(caller_channel)) {
>>>       tstatus = switch_core_session_read_frame()
>>>     ...
>>> 
>>> Any advice how to avoid extra delay in this situation?
>>> 
>>> _______________________________________________
>>> FreeSWITCH-users mailing list
>>> FreeSWITCH-users at lists.freeswitch.org
>>> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
>>> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
>>> http://www.freeswitch.org
> 
> 
> 
> _______________________________________________
> FreeSWITCH-users mailing list
> FreeSWITCH-users at lists.freeswitch.org
> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
> http://www.freeswitch.org