Javascript: inconsistent session.ready() result when originating a call
I'm using Javascript to originate a new outbound call. The Session ready() method returns inconsistent results when the call is answered. When it returns false, the session's causecode value is 0. Am I doing something wrong here, or could it be a bug? A simple test script and log output is below. I'm executing the script from the console using jsrun. I've noticed that switch_core_state_machine.c logs a state change when ready() returns true. I'm not sure if this is significant, but it might indicate a race condition. ---- test script ---- new_session = new Session( "{ignore_early_media=true}sofia/internal/1000%192.168.1.10" ); if ( new_session.ready() ) { console_log( "info", "Call connected.\n" ); // play audio.... } else { // the causecode is 0 when this fails on a successful call attempt console_log("err", "Call not connected. Cause: " + new_session.cause + "[" + new_session.causecode + "]\n" ); } ---- call connected log ---- [NOTICE] sofia.c:4851 Channel [sofia/internal/1000] has been answered [DEBUG] switch_ivr_originate.c:3273 Originate Resulted in Success: [sofia/internal/1000] [DEBUG] mod_spidermonkey.c:2866 (sofia/internal/1000) State Change CS_CONSUME_MEDIA -> CS_SOFT_EXECUTE [DEBUG] switch_core_session.c:1027 Send signal sofia/internal/1000 [BREAK] [DEBUG] switch_core_state_machine.c:314 (sofia/internal/1000) Running State Change CS_SOFT_EXECUTE [INFO] originate.js:1 Call connected. [DEBUG] switch_core_state_machine.c:354 (sofia/internal/1000) State SOFT_EXECUTE [DEBUG] mod_sofia.c:544 SOFIA SOFT_EXECUTE [DEBUG] switch_core_state_machine.c:200 sofia/internal/1000 Standard SOFT_EXECUTE [DEBUG] switch_core_state_machine.c:354 (sofia/internal/1000) State SOFT_EXECUTE going to sleep ---- call not connected log ---- [NOTICE] sofia.c:4851 Channel [sofia/internal/1000] has been answered [DEBUG] switch_ivr_originate.c:3273 Originate Resulted in Success: [sofia/internal/1000] [DEBUG] mod_spidermonkey.c:2866 (sofia/internal/1000) State Change CS_CONSUME_MEDIA -> CS_SOFT_EXECUTE [DEBUG] switch_core_session.c:1027 Send signal sofia/internal/1000 [BREAK] [ERR] originate.js:1 Call not connected. Cause: NONE(0) [DEBUG] switch_channel.c:2261 (sofia/internal/1000) Callstate Change ACTIVE -> HANGUP [NOTICE] mod_spidermonkey.c:3066 Hangup sofia/internal/1000 [CS_SOFT_EXECUTE] [NORMAL_CLEARING]
I would do the following: try { new_session = new Session( "sofia/internal/1000%192.168.1.10" ); console_log( "info", "Call connected.\n" ); // play audio.... } catch (e) { // the causecode is 0 when this fails on a successful call attempt console_log("err", "Call not connected. Cause: " + new_session.cause + "[" + new_session.causecode + "]\n" ); } Thanks, Stephen C -All of my email addresses go to the same place -Save Paper, think before you print On Fri, Jun 25, 2010 at 12:12 PM, Marc Kellem <mkellem@vontoo.com> wrote:
I'm using Javascript to originate a new outbound call. The Session ready() method returns inconsistent results when the call is answered. When it returns false, the session's causecode value is 0. Am I doing something wrong here, or could it be a bug?
A simple test script and log output is below. I'm executing the script from the console using jsrun. I've noticed that switch_core_state_machine.c logs a state change when ready() returns true. I'm not sure if this is significant, but it might indicate a race condition.
---- test script ----
new_session = new Session( "{ignore_early_media=true}sofia/internal/1000%192.168.1.10" ); if ( new_session.ready() ) { console_log( "info", "Call connected.\n" ); // play audio.... } else { // the causecode is 0 when this fails on a successful call attempt console_log("err", "Call not connected. Cause: " + new_session.cause + "[" + new_session.causecode + "]\n" ); }
---- call connected log ----
[NOTICE] sofia.c:4851 Channel [sofia/internal/1000] has been answered [DEBUG] switch_ivr_originate.c:3273 Originate Resulted in Success: [sofia/internal/1000] [DEBUG] mod_spidermonkey.c:2866 (sofia/internal/1000) State Change CS_CONSUME_MEDIA -> CS_SOFT_EXECUTE [DEBUG] switch_core_session.c:1027 Send signal sofia/internal/1000 [BREAK] [DEBUG] switch_core_state_machine.c:314 (sofia/internal/1000) Running State Change CS_SOFT_EXECUTE [INFO] originate.js:1 Call connected. [DEBUG] switch_core_state_machine.c:354 (sofia/internal/1000) State SOFT_EXECUTE [DEBUG] mod_sofia.c:544 SOFIA SOFT_EXECUTE [DEBUG] switch_core_state_machine.c:200 sofia/internal/1000 Standard SOFT_EXECUTE [DEBUG] switch_core_state_machine.c:354 (sofia/internal/1000) State SOFT_EXECUTE going to sleep
---- call not connected log ----
[NOTICE] sofia.c:4851 Channel [sofia/internal/1000] has been answered [DEBUG] switch_ivr_originate.c:3273 Originate Resulted in Success: [sofia/internal/1000] [DEBUG] mod_spidermonkey.c:2866 (sofia/internal/1000) State Change CS_CONSUME_MEDIA -> CS_SOFT_EXECUTE [DEBUG] switch_core_session.c:1027 Send signal sofia/internal/1000 [BREAK] [ERR] originate.js:1 Call not connected. Cause: NONE(0) [DEBUG] switch_channel.c:2261 (sofia/internal/1000) Callstate Change ACTIVE -> HANGUP [NOTICE] mod_spidermonkey.c:3066 Hangup sofia/internal/1000 [CS_SOFT_EXECUTE] [NORMAL_CLEARING]
_______________________________________________ FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
Stephen - I wrapped everything in a try/catch block like you suggested. The script does not throw an exception. On Sat, Jun 26, 2010 at 7:20 AM, Stephen Cattaneo <stephen@mymessage.us>wrote:
I would do the following:
try { new_session = new Session( "sofia/internal/1000%192.168.1.10" );
console_log( "info", "Call connected.\n" ); // play audio.... } catch (e)
{ // the causecode is 0 when this fails on a successful call attempt console_log("err", "Call not connected. Cause: " + new_session.cause + "[" + new_session.causecode + "]\n" );
}
are the logs any different? Thanks, Stephen C -All of my email addresses go to the same place -Save Paper, think before you print On Mon, Jun 28, 2010 at 9:51 AM, Marc Kellem <mkellem@vontoo.com> wrote:
Stephen - I wrapped everything in a try/catch block like you suggested. The script does not throw an exception.
On Sat, Jun 26, 2010 at 7:20 AM, Stephen Cattaneo <stephen@mymessage.us>wrote:
I would do the following:
try { new_session = new Session( "sofia/internal/1000%192.168.1.10" );
console_log( "info", "Call connected.\n" ); // play audio.... } catch (e)
{ // the causecode is 0 when this fails on a successful call attempt console_log("err", "Call not connected. Cause: " + new_session.cause + "[" + new_session.causecode + "]\n" );
}
_______________________________________________ FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
try latest GIT and see if it is any better. On Mon, Jun 28, 2010 at 8:56 AM, stephen at stephenjc <stephen@stephenjc.com
wrote:
are the logs any different?
Thanks, Stephen C -All of my email addresses go to the same place -Save Paper, think before you print
On Mon, Jun 28, 2010 at 9:51 AM, Marc Kellem <mkellem@vontoo.com> wrote:
Stephen - I wrapped everything in a try/catch block like you suggested. The script does not throw an exception.
On Sat, Jun 26, 2010 at 7:20 AM, Stephen Cattaneo <stephen@mymessage.us>wrote:
I would do the following:
try { new_session = new Session( "sofia/internal/1000%192.168.1.10" );
console_log( "info", "Call connected.\n" ); // play audio.... } catch (e)
{ // the causecode is 0 when this fails on a successful call attempt console_log("err", "Call not connected. Cause: " + new_session.cause + "[" + new_session.causecode + "]\n" );
}
_______________________________________________ FreeSWITCH-users mailing list FreeSWITCH-users@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@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/ Twitter: http://twitter.com/FreeSWITCH_wire AIM: anthm MSN:anthony_minessale@hotmail.com <MSN%3Aanthony_minessale@hotmail.com> GTALK/JABBER/PAYPAL:anthony.minessale@gmail.com<PAYPAL%3Aanthony.minessale@gmail.com> IRC: irc.freenode.net #freeswitch FreeSWITCH Developer Conference sip:888@conference.freeswitch.org <sip%3A888@conference.freeswitch.org> googletalk:conf+888@conference.freeswitch.org<googletalk%3Aconf%2B888@conference.freeswitch.org> pstn:+19193869900
I did a fresh checkout/install of the latest GIT. Now switch_core_sqldb.c is logging errors when I run the script. When you filter out those errors, ready() still returns false and causecode=0. 2010-06-28 12:14:13.653989 [INFO] sofia.c:662 sofia/internal/1000 Update Callee ID to "1000" <1000> 2010-06-28 12:14:13.721843 [ERR] switch_core_sqldb.c:730 SQL ERR: [select sip_subscriptions.proto,sip_subscriptions.sip_user,sip_subscriptions.sip_host,sip_subscriptions.sub_to_user,sip_subscriptions.sub_to_host,sip_subscriptions.event,sip_subscriptions.contact,sip_subscriptions.call_id,sip_subscriptions.full_from,sip_subscriptions.full_via,sip_subscriptions.expires,sip_subscriptions.user_agent,sip_subscriptions.accept,sip_subscriptions.profile_name,'CS_ROUTING','unknown','192.168.1.10',sip_presence.status,sip_presence.rpid from sip_subscriptions left join sip_presence on (sip_subscriptions.sub_to_user=sip_presence.sip_user and sip_subscriptions.sub_to_host=sip_presence.sip_host and sip_subscriptions.profile_name=sip_presence.profile_name) where sip_subscriptions.expires > -1 and (event='presence' or event='dialog') and sub_to_user='1000' and (sub_to_host='192.168.1.10' or presence_hosts like '%192.168.1.10%') and (sip_subscriptions.profile_name = 'internal' or sip_subscriptions.presence_hosts != sip_subscriptions.sub_to_host)] library routine called out of sequence 2010-06-28 12:14:13.721843 [ERR] switch_core_sqldb.c:730 SQL ERR: [select sip_subscriptions.proto,sip_subscriptions.sip_user,sip_subscriptions.sip_host,sip_subscriptions.sub_to_user,sip_subscriptions.sub_to_host,sip_subscriptions.event,sip_subscriptions.contact,sip_subscriptions.call_id,sip_subscriptions.full_from,sip_subscriptions.full_via,sip_subscriptions.expires,sip_subscriptions.user_agent,sip_subscriptions.accept,sip_subscriptions.profile_name,'CS_CONSUME_MEDIA','unknown','192.168.1.10',sip_presence.status,sip_presence.rpid from sip_subscriptions left join sip_presence on (sip_subscriptions.sub_to_user=sip_presence.sip_user and sip_subscriptions.sub_to_host=sip_presence.sip_host and sip_subscriptions.profile_name=sip_presence.profile_name) where sip_subscriptions.expires > -1 and (event='presence' or event='dialog') and sub_to_user='1000' and (sub_to_host='192.168.1.10' or presence_hosts like '%192.168.1.10%') and (sip_subscriptions.profile_name = 'internal' or sip_subscriptions.presence_hosts != sip_subscriptions.sub_to_host)] library routine called out of sequence 2010-06-28 12:14:13.886956 [NOTICE] sofia.c:4369 Ring-Ready sofia/internal/1000! 2010-06-28 12:14:15.819755 [ERR] switch_core_sqldb.c:411 SQL ERR [library routine called out of sequence] update sip_dialogs set state='confirmed',presence_id='1000@192.168.1.10',presence_data='' where uuid='313369b2-82d0-11df-84f0-078cbd7c22e4'; 2010-06-28 12:14:15.825582 [NOTICE] sofia.c:4855 Channel [sofia/internal/1000] has been answered 2010-06-28 12:14:15.825582 [ERR] originate.js:1 Call not connected. Cause: NONE[0] ... [lots of switch_core_sqldb.c errors ] ... On Mon, Jun 28, 2010 at 10:09 AM, Anthony Minessale < anthony.minessale@gmail.com> wrote:
try latest GIT and see if it is any better.
update again small hiccup in the revisions On Mon, Jun 28, 2010 at 11:33 AM, Marc Kellem <mkellem@vontoo.com> wrote:
I did a fresh checkout/install of the latest GIT. Now switch_core_sqldb.c is logging errors when I run the script. When you filter out those errors, ready() still returns false and causecode=0.
2010-06-28 12:14:13.653989 [INFO] sofia.c:662 sofia/internal/1000 Update Callee ID to "1000" <1000> 2010-06-28 12:14:13.721843 [ERR] switch_core_sqldb.c:730 SQL ERR: [select sip_subscriptions.proto,sip_subscriptions.sip_user,sip_subscriptions.sip_host,sip_subscriptions.sub_to_user,sip_subscriptions.sub_to_host,sip_subscriptions.event,sip_subscriptions.contact,sip_subscriptions.call_id,sip_subscriptions.full_from,sip_subscriptions.full_via,sip_subscriptions.expires,sip_subscriptions.user_agent,sip_subscriptions.accept,sip_subscriptions.profile_name,'CS_ROUTING','unknown','192.168.1.10',sip_presence.status,sip_presence.rpid from sip_subscriptions left join sip_presence on (sip_subscriptions.sub_to_user=sip_presence.sip_user and sip_subscriptions.sub_to_host=sip_presence.sip_host and sip_subscriptions.profile_name=sip_presence.profile_name) where sip_subscriptions.expires > -1 and (event='presence' or event='dialog') and sub_to_user='1000' and (sub_to_host='192.168.1.10' or presence_hosts like '%192.168.1.10%') and (sip_subscriptions.profile_name = 'internal' or sip_subscriptions.presence_hosts != sip_subscriptions.sub_to_host)] library routine called out of sequence 2010-06-28 12:14:13.721843 [ERR] switch_core_sqldb.c:730 SQL ERR: [select sip_subscriptions.proto,sip_subscriptions.sip_user,sip_subscriptions.sip_host,sip_subscriptions.sub_to_user,sip_subscriptions.sub_to_host,sip_subscriptions.event,sip_subscriptions.contact,sip_subscriptions.call_id,sip_subscriptions.full_from,sip_subscriptions.full_via,sip_subscriptions.expires,sip_subscriptions.user_agent,sip_subscriptions.accept,sip_subscriptions.profile_name,'CS_CONSUME_MEDIA','unknown','192.168.1.10',sip_presence.status,sip_presence.rpid from sip_subscriptions left join sip_presence on (sip_subscriptions.sub_to_user=sip_presence.sip_user and sip_subscriptions.sub_to_host=sip_presence.sip_host and sip_subscriptions.profile_name=sip_presence.profile_name) where sip_subscriptions.expires > -1 and (event='presence' or event='dialog') and sub_to_user='1000' and (sub_to_host='192.168.1.10' or presence_hosts like '%192.168.1.10%') and (sip_subscriptions.profile_name = 'internal' or sip_subscriptions.presence_hosts != sip_subscriptions.sub_to_host)] library routine called out of sequence 2010-06-28 12:14:13.886956 [NOTICE] sofia.c:4369 Ring-Ready sofia/internal/1000! 2010-06-28 12:14:15.819755 [ERR] switch_core_sqldb.c:411 SQL ERR [library routine called out of sequence] update sip_dialogs set state='confirmed',presence_id='1000@192.168.1.10',presence_data='' where uuid='313369b2-82d0-11df-84f0-078cbd7c22e4';
2010-06-28 12:14:15.825582 [NOTICE] sofia.c:4855 Channel [sofia/internal/1000] has been answered 2010-06-28 12:14:15.825582 [ERR] originate.js:1 Call not connected. Cause: NONE[0] ... [lots of switch_core_sqldb.c errors ] ...
On Mon, Jun 28, 2010 at 10:09 AM, Anthony Minessale < anthony.minessale@gmail.com> wrote:
try latest GIT and see if it is any better.
_______________________________________________ FreeSWITCH-users mailing list FreeSWITCH-users@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/ Twitter: http://twitter.com/FreeSWITCH_wire AIM: anthm MSN:anthony_minessale@hotmail.com <MSN%3Aanthony_minessale@hotmail.com> GTALK/JABBER/PAYPAL:anthony.minessale@gmail.com<PAYPAL%3Aanthony.minessale@gmail.com> IRC: irc.freenode.net #freeswitch FreeSWITCH Developer Conference sip:888@conference.freeswitch.org <sip%3A888@conference.freeswitch.org> googletalk:conf+888@conference.freeswitch.org<googletalk%3Aconf%2B888@conference.freeswitch.org> pstn:+19193869900
The sqldb errors are gone but the original problem still exists. Let me know if you need more information. Thanks for looking into it. -- Marc On Mon, Jun 28, 2010 at 12:44 PM, Anthony Minessale < anthony.minessale@gmail.com> wrote:
update again small hiccup in the revisions
On Mon, Jun 28, 2010 at 11:33 AM, Marc Kellem <mkellem@vontoo.com> wrote:
I did a fresh checkout/install of the latest GIT. Now switch_core_sqldb.c is logging errors when I run the script. When you filter out those errors, ready() still returns false and causecode=0.
2010-06-28 12:14:13.653989 [INFO] sofia.c:662 sofia/internal/1000 Update Callee ID to "1000" <1000> 2010-06-28 12:14:13.721843 [ERR] switch_core_sqldb.c:730 SQL ERR: [select sip_subscriptions.proto,sip_subscriptions.sip_user,sip_subscriptions.sip_host,sip_subscriptions.sub_to_user,sip_subscriptions.sub_to_host,sip_subscriptions.event,sip_subscriptions.contact,sip_subscriptions.call_id,sip_subscriptions.full_from,sip_subscriptions.full_via,sip_subscriptions.expires,sip_subscriptions.user_agent,sip_subscriptions.accept,sip_subscriptions.profile_name,'CS_ROUTING','unknown','192.168.1.10',sip_presence.status,sip_presence.rpid from sip_subscriptions left join sip_presence on (sip_subscriptions.sub_to_user=sip_presence.sip_user and sip_subscriptions.sub_to_host=sip_presence.sip_host and sip_subscriptions.profile_name=sip_presence.profile_name) where sip_subscriptions.expires > -1 and (event='presence' or event='dialog') and sub_to_user='1000' and (sub_to_host='192.168.1.10' or presence_hosts like '%192.168.1.10%') and (sip_subscriptions.profile_name = 'internal' or sip_subscriptions.presence_hosts != sip_subscriptions.sub_to_host)] library routine called out of sequence 2010-06-28 12:14:13.721843 [ERR] switch_core_sqldb.c:730 SQL ERR: [select sip_subscriptions.proto,sip_subscriptions.sip_user,sip_subscriptions.sip_host,sip_subscriptions.sub_to_user,sip_subscriptions.sub_to_host,sip_subscriptions.event,sip_subscriptions.contact,sip_subscriptions.call_id,sip_subscriptions.full_from,sip_subscriptions.full_via,sip_subscriptions.expires,sip_subscriptions.user_agent,sip_subscriptions.accept,sip_subscriptions.profile_name,'CS_CONSUME_MEDIA','unknown','192.168.1.10',sip_presence.status,sip_presence.rpid from sip_subscriptions left join sip_presence on (sip_subscriptions.sub_to_user=sip_presence.sip_user and sip_subscriptions.sub_to_host=sip_presence.sip_host and sip_subscriptions.profile_name=sip_presence.profile_name) where sip_subscriptions.expires > -1 and (event='presence' or event='dialog') and sub_to_user='1000' and (sub_to_host='192.168.1.10' or presence_hosts like '%192.168.1.10%') and (sip_subscriptions.profile_name = 'internal' or sip_subscriptions.presence_hosts != sip_subscriptions.sub_to_host)] library routine called out of sequence 2010-06-28 12:14:13.886956 [NOTICE] sofia.c:4369 Ring-Ready sofia/internal/1000! 2010-06-28 12:14:15.819755 [ERR] switch_core_sqldb.c:411 SQL ERR [library routine called out of sequence] update sip_dialogs set state='confirmed',presence_id='1000@192.168.1.10',presence_data='' where uuid='313369b2-82d0-11df-84f0-078cbd7c22e4';
2010-06-28 12:14:15.825582 [NOTICE] sofia.c:4855 Channel [sofia/internal/1000] has been answered 2010-06-28 12:14:15.825582 [ERR] originate.js:1 Call not connected. Cause: NONE[0] ... [lots of switch_core_sqldb.c errors ] ...
On Mon, Jun 28, 2010 at 10:09 AM, Anthony Minessale < anthony.minessale@gmail.com> wrote:
try latest GIT and see if it is any better.
_______________________________________________ FreeSWITCH-users mailing list FreeSWITCH-users@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/ Twitter: http://twitter.com/FreeSWITCH_wire
AIM: anthm MSN:anthony_minessale@hotmail.com <MSN%3Aanthony_minessale@hotmail.com> GTALK/JABBER/PAYPAL:anthony.minessale@gmail.com<PAYPAL%3Aanthony.minessale@gmail.com> IRC: irc.freenode.net #freeswitch
FreeSWITCH Developer Conference sip:888@conference.freeswitch.org <sip%3A888@conference.freeswitch.org> googletalk:conf+888@conference.freeswitch.org<googletalk%3Aconf%2B888@conference.freeswitch.org> pstn:+19193869900
_______________________________________________ FreeSWITCH-users mailing list FreeSWITCH-users@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 - I ported my test script to Lua and it has the same problem. newSession = freeswitch.Session("{ignore_early_media=true}sofia/ 192.168.1.10/1000") if newSession:ready() then freeswitch.consoleLog("info", "Call connected\n" ) else local cause = newSession:hangupCause() freeswitch.consoleLog("err", "Call not connected. Cause: " .. cause .. "\n" ) end
participants (4)
-
Anthony Minessale
-
Marc Kellem
-
stephen at stephenjc
-
Stephen Cattaneo