[Freeswitch-users] javascript originate timeout problem

Anthony Minessale anthony.minessale at gmail.com
Wed Apr 16 07:18:44 PDT 2008


Are you using the transfer app from your javascript?
If so, and the script is running on the target channel that is being
transferred it will cause the script to exit because
transfer is effectively hangup as the act of transfer stops all execution of
apps and sends the call to the dialplan.

You can instead session.execute("execute_extenson", "1000");
Which unlike transfer runs the extension inline and returns back to the same
place.

On Wed, Apr 16, 2008 at 8:29 AM, Jonas Gauffin <jonas.gauffin at gmail.com>
wrote:

> Hello again =)
>
> I've made a call queue in javascript where the js takes orders from a
> server through a socket.
> The server monitors all extensions (through eventsocket) in the queue
> and tells the javascript to originate the call to a extension as soon
> as it becomes idle.
>
> Everything works fine except when the extension do not answer.
> Freeswitch seems to kill the javascript and executes the dialplan
> instead.
> This only happens when the destination do not answer.
>
> Small log (from when entering the javascript and forward)
>
> 2008-04-16 15:21:01 [CONSOLE] mod_spidermonkey_socket.c:109
> socket_connect() Connecting to: 127.0.0.1:23341.
> 2008-04-16 15:21:01 [DEBUG] switch_core_session.c:383
> switch_core_session_receive_message() Kill
> sofia/default/anonymous at anonymous.invalid [BREAK]
> 2008-04-16 15:21:01 [NOTICE] mod_spidermonkey.c:1948 session_answer()
> Channel [sofia/default/anonymous at anonymous.invalid] has been answered
> 2008-04-16 15:21:01 [DEBUG] mod_spidermonkey.c:3132 js_api_use() Loading
> Socket
> 2008-04-16 15:21:01 [DEBUG] log.js:7 console_log() DEBUG: Sending register
> 2008-04-16 15:21:01 [DEBUG] sofia.c:1648 sofia_handle_sip_i_state()
> Channel sofia/default/anonymous at anonymous.invalid entering state
> [completed]
> 2008-04-16 15:21:01 [DEBUG] sofia.c:1648 sofia_handle_sip_i_state()
> Channel sofia/default/anonymous at anonymous.invalid entering state
> [ready]
> 2008-04-16 15:21:02 [DEBUG] log.js:7 console_log() DEBUG: Receivied:
> transfer   20      192.168.1.110   u1000022
> 2008-04-16 15:21:02 [DEBUG] log.js:7 console_log() DEBUG: Calling
> sofia/192.168.1.110/u1000022
> 2008-04-16 <http://192.168.1.110/u10000222008-04-16> 15:21:02 [DEBUG]
> log.js:7 console_log() DEBUG: DESTINATION:
> {ignore_early_media=true,originate_timeout=15}sofia/192.168.1.110/u1000022
> 2008-04-16 <http://192.168.1.110/u10000222008-04-16> 15:21:02 [DEBUG]
> switch_ivr_originate.c:607
> switch_ivr_originate() variable string 0 = [ignore_early_media=true]
> 2008-04-16 15:21:02 [DEBUG] switch_ivr_originate.c:607
> switch_ivr_originate() variable string 1 = [originate_timeout=15]
> 2008-04-16 15:21:02 [NOTICE] switch_channel.c:531
> switch_channel_set_name() New Channel sofia/default/u1000022
> [91daaf25-4f6f-8848-8d10-596f45c13238]
> 2008-04-16 15:21:02 [DEBUG] mod_sofia.c:1830 sofia_outgoing_channel()
> sofia/default/u1000022 State Change CS_NEW -> CS_INIT
> 2008-04-16 15:21:02 [DEBUG] switch_core_session.c:670
> switch_core_session_signal_state_change() Kill sofia/default/u1000022
> [BREAK]
> 2008-04-16 15:21:02 [DEBUG] switch_core_state_machine.c:364
> switch_core_session_run() sofia/default/u1000022 Running State Change
> CS_INIT
> 2008-04-16 15:21:02 [DEBUG] switch_core_state_machine.c:413
> switch_core_session_run() (sofia/default/u1000022) State INIT
> 2008-04-16 15:21:02 [DEBUG] mod_sofia.c:80 sofia_on_init()
> sofia/default/u1000022 SOFIA INIT
> 2008-04-16 15:21:02 [DEBUG] mod_sofia.c:107 sofia_on_init()
> sofia/default/u1000022 State Change CS_INIT -> CS_RING
> 2008-04-16 15:21:02 [DEBUG] switch_core_session.c:670
> switch_core_session_signal_state_change() Kill sofia/default/u1000022
> [BREAK]
> 2008-04-16 15:21:02 [DEBUG] switch_core_state_machine.c:413
> switch_core_session_run() (sofia/default/u1000022) State INIT going to
> sleep
> 2008-04-16 15:21:02 [DEBUG] switch_core_state_machine.c:364
> switch_core_session_run() sofia/default/u1000022 Running State Change
> CS_RING
> 2008-04-16 15:21:02 [DEBUG] sofia.c:222 sofia_event_callback() event
> [nua_i_state] status [0][INVITE sent] session: sofia/default/u1000022
> 2008-04-16 15:21:02 [DEBUG] sofia.c:1648 sofia_handle_sip_i_state()
> Channel sofia/default/u1000022 entering state [calling]
> 2008-04-16 15:21:02 [DEBUG] switch_ivr_originate.c:951
> switch_ivr_originate() Raw Codec Activation Success L16 at 8000hz 1
> channel 20ms
> 2008-04-16 15:21:02 [DEBUG] switch_core_state_machine.c:418
> switch_core_session_run() (sofia/default/u1000022) State RING
> 2008-04-16 15:21:02 [DEBUG] mod_sofia.c:119 sofia_on_ring()
> sofia/default/u1000022 SOFIA RING
> 2008-04-16 15:21:02 [DEBUG] switch_ivr_originate.c:55
> originate_on_ring() sofia/default/u1000022 State Change CS_RING ->
> CS_HOLD
> 2008-04-16 15:21:02 [DEBUG] switch_core_session.c:670
> switch_core_session_signal_state_change() Kill sofia/default/u1000022
> [BREAK]
> 2008-04-16 15:21:02 [DEBUG] switch_core_state_machine.c:418
> switch_core_session_run() (sofia/default/u1000022) State RING going to
> sleep
> 2008-04-16 15:21:02 [DEBUG] switch_core_state_machine.c:364
> switch_core_session_run() sofia/default/u1000022 Running State Change
> CS_HOLD
> 2008-04-16 15:21:02 [DEBUG] switch_core_state_machine.c:440
> switch_core_session_run() (sofia/default/u1000022) State HOLD
> 2008-04-16 15:21:02 [DEBUG] sofia.c:222 sofia_event_callback() event
> [nua_r_invite] status [180][Ringing] session: sofia/default/u1000022
> 2008-04-16 15:21:02 [DEBUG] sofia.c:222 sofia_event_callback() event
> [nua_i_state] status [180][Ringing] session: sofia/default/u1000022
> 2008-04-16 15:21:02 [DEBUG] sofia.c:1648 sofia_handle_sip_i_state()
> Channel sofia/default/u1000022 entering state [proceeding]
> 2008-04-16 15:21:02 [NOTICE] sofia.c:1686 sofia_handle_sip_i_state()
> Ring-Ready sofia/default/u1000022!
> 2008-04-16 15:21:02 [DEBUG] switch_core_session.c:383
> switch_core_session_receive_message() Kill
> sofia/default/anonymous at anonymous.invalid [BREAK]
> 2008-04-16 15:21:02 [DEBUG] sofia.c:350 sofia_event_callback()
> nua_r_prack: unknown event 39: 200 OK
> 2008-04-16 15:21:33 [DEBUG] sofia.c:1648 sofia_handle_sip_i_state()
> Channel sofia/default/u1000022 entering state [calling]
> 2008-04-16 15:21:33 [NOTICE] switch_channel.c:531
> switch_channel_set_name() New Channel sofia/default/1202 at 192.168.1.110
> [e59265ba-8486-7546-af60-8da7b25e87
> 2008-04-16 15:21:33 [DEBUG] sofia.c:1648 sofia_handle_sip_i_state()
> Channel sofia/default/1202 at 192.168.1.110 entering state [received]
> 2008-04-16 15:21:33 [DEBUG] switch_core_state_machine.c:364
> switch_core_session_run() sofia/default/1202 at 192.168.1.110 Running
> State Change CS_NEW
> 2008-04-16 15:21:33 [DEBUG] sofia.c:1652 sofia_handle_sip_i_state() Remote
> SDP:
> v=0
> o=FreeSWITCH 4934107701406015977 4314135494661389300 IN IP4 192.168.1.110
> s=FreeSWITCH
> c=IN IP4 192.168.1.110
> t=0 0
> a=sendrecv
> m=audio 25866 RTP/AVP 0 8 9 101 13
> a=rtpmap:0 PCMU/8000
> a=rtpmap:8 PCMA/8000
> a=rtpmap:9 G722/8000
> a=rtpmap:101 telephone-event/8000
> a=fmtp:101 0-16
> a=rtpmap:13 CN/8000
> a=ptime:20
>
> 2008-04-16 15:21:33 [DEBUG] sofia_glue.c:2011
> sofia_glue_negotiate_sdp() Audio Codec Compare
> [PCMU:0:8000]/[PCMU:0:8000]
> 2008-04-16 15:21:33 [DEBUG] sofia_glue.c:1333
> sofia_glue_tech_set_codec() Set Codec sofia/default/1202 at 192.168.1.110
> PCMU/8000 20 ms 160 samples
> 2008-04-16 15:21:33 [DEBUG] switch_core_state_machine.c:368
> switch_core_session_run() (sofia/default/1202 at 192.168.1.110) State NEW
> 2008-04-16 15:21:33 [DEBUG] sofia_glue.c:1975
> sofia_glue_negotiate_sdp() Set 2833 dtmf payload to 101
> 2008-04-16 15:21:33 [DEBUG] sofia_glue.c:1983
> sofia_glue_negotiate_sdp() Set comfort noise payload to 13
> 2008-04-16 15:21:33 [DEBUG] sofia.c:1789 sofia_handle_sip_i_state()
> sofia/default/1202 at 192.168.1.110 State Change CS_NEW -> CS_INIT
> 2008-04-16 15:21:33 [DEBUG] switch_core_session.c:670
> switch_core_session_signal_state_change() Kill
> sofia/default/1202 at 192.168.1.110 [BREAK]
> 2008-04-16 15:21:33 [DEBUG] switch_core_state_machine.c:364
> switch_core_session_run() sofia/default/1202 at 192.168.1.110 Running
> State Change CS_INIT
> 2008-04-16 15:21:33 [DEBUG] switch_core_state_machine.c:413
> switch_core_session_run() (sofia/default/1202 at 192.168.1.110) State
> INIT
> 2008-04-16 15:21:33 [DEBUG] mod_sofia.c:80 sofia_on_init()
> sofia/default/1202 at 192.168.1.110 SOFIA INIT
> 2008-04-16 15:21:33 [DEBUG] mod_sofia.c:107 sofia_on_init()
> sofia/default/1202 at 192.168.1.110 State Change CS_INIT -> CS_RING
> 2008-04-16 15:21:33 [DEBUG] switch_core_session.c:670
> switch_core_session_signal_state_change() Kill
> sofia/default/1202 at 192.168.1.110 [BREAK]
> 2008-04-16 15:21:33 [DEBUG] switch_core_state_machine.c:413
> switch_core_session_run() (sofia/default/1202 at 192.168.1.110) State
> INIT going to sleep
> 2008-04-16 15:21:33 [DEBUG] switch_core_state_machine.c:364
> switch_core_session_run() sofia/default/1202 at 192.168.1.110 Running
> State Change CS_RING
> 2008-04-16 15:21:33 [DEBUG] switch_core_state_machine.c:418
> switch_core_session_run() (sofia/default/1202 at 192.168.1.110) State
> RING
> 2008-04-16 15:21:33 [DEBUG] mod_sofia.c:119 sofia_on_ring()
> sofia/default/1202 at 192.168.1.110 SOFIA RING
> 2008-04-16 15:21:33 [DEBUG] switch_core_state_machine.c:65
> switch_core_standard_on_ring() Standard RING
> sofia/default/1202 at 192.168.1.110
> 2008-04-16 15:21:33 [INFO] mod_dialplan_xml.c:223 dialplan_hunt()
> Processing Arne Rubin->82378009 at public
> 2008-04-16 15:21:35 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test
> conditions destination_number(82378009) =~ /^\+4623666(12[01][0-9])$/
> 2008-04-16 15:21:35 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex
> mismatch
> 2008-04-16 15:21:35 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test
> conditions destination_number(82378009) =~ /^(5551212)$/
> 2008-04-16 15:21:35 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex
> mismatch
> 2008-04-16 15:21:35 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test
> conditions destination_number(82378009) =~ /1202/
> 2008-04-16 15:21:35 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex
> mismatch
> 2008-04-16 15:21:35 [INFO] switch_core_state_machine.c:113
> switch_core_standard_on_ring() No Route, Aborting
>
> _______________________________________________
> 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
>



-- 
Anthony Minessale II

FreeSWITCH http://www.freeswitch.org/
ClueCon http://www.cluecon.com/

AIM: anthm
MSN:anthony_minessale at hotmail.com <MSN%3Aanthony_minessale at hotmail.com>
GTALK/JABBER/PAYPAL:anthony.minessale at gmail.com<PAYPAL%3Aanthony.minessale at gmail.com>
IRC: irc.freenode.net #freeswitch

FreeSWITCH Developer Conference
sip:888 at conference.freeswitch.org <sip%3A888 at conference.freeswitch.org>
iax:guest at conference.freeswitch.org/888
googletalk:conf+888 at conference.freeswitch.org<googletalk%3Aconf%2B888 at conference.freeswitch.org>
pstn:213-799-1400
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20080416/956f1137/attachment-0002.html 


More information about the FreeSWITCH-users mailing list