[Freeswitch-users] 10 seconds delay on fallback

[Sergey Okhapkin]

Thank you for the heads up, will do.

On Wednesday 13 January 2010, Michael Jerris wrote:
> 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=]sof
> >ia/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-user
> >>>s 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
>
> _______________________________________________
> 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