Some IVRs not connecting
-
I have setup IVRs at extensions 5000 through 5005 with recordings. Only 5000 and 5001 work as expected, while dialing the others internally or externally causes a hangup or something like it. I have attached the latter portion of the debug log which was recorded while calling 5002 from local extension 1001.
To rule out the recording being an issue I have set IVR 5002 to use the same recording as 5000, but 5000 continues to function as expected while 5002 does not. I hit the default button on public.xml, dialplan.xml and vars.xml today while chasing another issue, so if the problem is there then I suppose others should also have seen it by now.
Suggestions?
Dialplan: sofia/internal/1001@burgess.myphotos.cc Regex (PASS) [5002] destination_number(5002) =~ /^5002$/ break=on-false Dialplan: sofia/internal/1001@burgess.myphotos.cc Action javascript(ivr_D46326DF-5688-FC88-45F4-2B629B60A0ED.js) 2009-05-15 21:57:03 [DEBUG] switch_core_state_machine.c:114 switch_core_standard_on_routing() (sofia/internal/1001@burgess.myphotos.cc) State Change CS_ROUTING -> CS_EXECUTE 2009-05-15 21:57:03 [DEBUG] switch_core_session.c:933 switch_core_session_signal_state_change() Send signal sofia/internal/1001@burgess.myphotos.cc [BREAK] 2009-05-15 21:57:03 [DEBUG] switch_core_state_machine.c:483 switch_core_session_run() (sofia/internal/1001@burgess.myphotos.cc) State ROUTING going to sleep 2009-05-15 21:57:03 [DEBUG] switch_core_state_machine.c:397 switch_core_session_run() (sofia/internal/1001@burgess.myphotos.cc) Running State Change CS_EXECUTE 2009-05-15 21:57:03 [DEBUG] switch_core_state_machine.c:490 switch_core_session_run() (sofia/internal/1001@burgess.myphotos.cc) State EXECUTE 2009-05-15 21:57:03 [DEBUG] mod_sofia.c:173 sofia_on_execute() sofia/internal/1001@burgess.myphotos.cc SOFIA EXECUTE 2009-05-15 21:57:03 [DEBUG] switch_core_state_machine.c:151 switch_core_standard_on_execute() sofia/internal/1001@burgess.myphotos.cc Standard EXECUTE EXECUTE sofia/internal/1001@burgess.myphotos.cc set(use_profile=nat) 2009-05-15 21:57:03 [DEBUG] mod_dptools.c:748 set_function() sofia/internal/1001@burgess.myphotos.cc SET [use_profile]=[nat] EXECUTE sofia/internal/1001@burgess.myphotos.cc set_user(default@burgess.myphotos.cc) EXECUTE sofia/internal/1001@burgess.myphotos.cc db(insert/burgess.myphotos.cc-spymap/1001/f160b39d-cd41-de11-b4ee-000024cbeb68) EXECUTE sofia/internal/1001@burgess.myphotos.cc db(insert/burgess.myphotos.cc-last_dial/1001/5002) EXECUTE sofia/internal/1001@burgess.myphotos.cc db(insert/burgess.myphotos.cc-last_dial/global/f160b39d-cd41-de11-b4ee-000024cbeb68) EXECUTE sofia/internal/1001@burgess.myphotos.cc javascript(ivr_D46326DF-5688-FC88-45F4-2B629B60A0ED.js) 2009-05-15 21:57:04 [NOTICE] switch_core_state_machine.c:179 switch_core_standard_on_execute() Hangup sofia/internal/1001@burgess.myphotos.cc [CS_EXECUTE] [NORMAL_CLEARING] 2009-05-15 21:57:04 [DEBUG] switch_channel.c:1641 switch_channel_perform_hangup() Send signal sofia/internal/1001@burgess.myphotos.cc [KILL] 2009-05-15 21:57:04 [DEBUG] switch_core_session.c:933 switch_core_session_signal_state_change() Send signal sofia/internal/1001@burgess.myphotos.cc [BREAK] 2009-05-15 21:57:04 [DEBUG] switch_core_state_machine.c:490 switch_core_session_run() (sofia/internal/1001@burgess.myphotos.cc) State EXECUTE going to sleep 2009-05-15 21:57:04 [DEBUG] switch_core_state_machine.c:397 switch_core_session_run() (sofia/internal/1001@burgess.myphotos.cc) Running State Change CS_HANGUP 2009-05-15 21:57:04 [DEBUG] switch_core_state_machine.c:433 switch_core_session_run() (sofia/internal/1001@burgess.myphotos.cc) State HANGUP 2009-05-15 21:57:04 [DEBUG] mod_sofia.c:323 sofia_on_hangup() Channel sofia/internal/1001@burgess.myphotos.cc hanging up, cause: NORMAL_CLEARING 2009-05-15 21:57:04 [DEBUG] mod_sofia.c:399 sofia_on_hangup() Responding to INVITE with: 480 2009-05-15 21:57:04 [DEBUG] switch_core_state_machine.c:46 switch_core_standard_on_hangup() sofia/internal/1001@burgess.myphotos.cc Standard HANGUP, cause: NORMAL_CLEARING 2009-05-15 21:57:04 [DEBUG] switch_core_state_machine.c:433 switch_core_session_run() (sofia/internal/1001@burgess.myphotos.cc) State HANGUP going to sleep 2009-05-15 21:57:04 [DEBUG] switch_core_state_machine.c:475 switch_core_session_run() (sofia/internal/1001@burgess.myphotos.cc) State Change CS_HANGUP -> CS_REPORTING 2009-05-15 21:57:04 [DEBUG] switch_core_session.c:933 switch_core_session_signal_state_change() Send signal sofia/internal/1001@burgess.myphotos.cc [BREAK] 2009-05-15 21:57:04 [DEBUG] switch_core_state_machine.c:397 switch_core_session_run() (sofia/internal/1001@burgess.myphotos.cc) Running State Change CS_REPORTING 2009-05-15 21:57:04 [DEBUG] switch_core_state_machine.c:607 switch_core_session_reporting_state() (sofia/internal/1001@burgess.myphotos.cc) State REPORTING 2009-05-15 21:57:04 [DEBUG] switch_core_state_machine.c:53 switch_core_standard_on_reporting() sofia/internal/1001@burgess.myphotos.cc Standard REPORTING, cause: NORMAL_CLEARING 2009-05-15 21:57:04 [DEBUG] switch_core_state_machine.c:607 switch_core_session_reporting_state() (sofia/internal/1001@burgess.myphotos.cc) State REPORTING going to sleep 2009-05-15 21:57:04 [DEBUG] switch_core_state_machine.c:410 switch_core_session_run() (sofia/internal/1001@burgess.myphotos.cc) State Change CS_REPORTING -> CS_DESTROY 2009-05-15 21:57:04 [DEBUG] switch_core_session.c:1067 switch_core_session_thread() Session 30 (sofia/internal/1001@burgess.myphotos.cc) Locked, Waiting on external entities 2009-05-15 21:57:04 [NOTICE] switch_core_session.c:1085 switch_core_session_thread() Session 30 (sofia/internal/1001@burgess.myphotos.cc) Ended 2009-05-15 21:57:04 [NOTICE] switch_core_session.c:1087 switch_core_session_thread() Close Channel sofia/internal/1001@burgess.myphotos.cc [CS_DESTROY] 2009-05-15 21:57:04 [DEBUG] switch_core_state_machine.c:559 switch_core_session_destroy_state() (sofia/internal/1001@burgess.myphotos.cc) State DESTROY 2009-05-15 21:57:04 [DEBUG] mod_sofia.c:240 sofia_on_destroy() sofia/internal/1001@burgess.myphotos.cc SOFIA DESTROY 2009-05-15 21:57:04 [DEBUG] switch_core_state_machine.c:60 switch_core_standard_on_destroy() sofia/internal/1001@burgess.myphotos.cc Standard DESTROY 2009-05-15 21:57:04 [DEBUG] switch_core_state_machine.c:559 switch_core_session_destroy_state() (sofia/internal/1001@burgess.myphotos.cc) State DESTROY going to sleep 2009-05-15 21:57:04 [DEBUG] switch_core_state_machine.c:559 switch_core_session_destroy_state() (sofia/internal/1001@burgess.myphotos.cc) State DESTROY going to sleep
-
Can you please open /usr/local/freeswitch/scripts/ivr_D46326DF-5688-FC88-45F4-2B629B60A0ED.js and then attach it to the this thread. Then I will take a look at it on monday.
Best Regards,
Mark
-
$ cat /usr/local/freeswitch/scripts/ivr_D46326DF-5688-FC88-45F4-2B629B60A0ED.js var condition = true; var domain = "burgess.myphotos.cc"; //by default this is the ipv4 address of FreeSWITCH used for transfer to voicemail var digitmaxlength = 0; var objdate = new Date(); var adjusthours = 0; //Adjust Server time that is set to GMT 7 hours var adjustoperator = "-"; //+ or - if (adjustoperator == "-") { var objdate2 = new Date(objdate.getFullYear(),objdate.getMonth(),objdate.getDate(),(objdate.getHours() - adjusthours),objdate.getMinutes(),objdate.getSeconds()); } if (adjustoperator == "+") { var objdate2 = new Date(objdate.getFullYear(),objdate.getMonth(),objdate.getDate(),(objdate.getHours() + adjusthours),objdate.getMinutes(),objdate.getSeconds()); } var Hours = objdate2.getHours(); var Mins = objdate2.getMinutes(); var Seconds = objdate2.getSeconds(); var Month = objdate2.getMonth() + 1; var Date = objdate2.getDate(); var Year = objdate2.getYear() var Day = objdate2.getDay()+1; var exit = false; //console_log( "info", "IVR Server Time is: "+Hours+":"+Mins+" \n" ); function mycb( session, type, obj, arg ) { try { if ( type == "dtmf" ) { console_log( "info", "digit: "+obj.digit+"\n" ); if ( obj.digit == "#" ) { //console_log( "info", "detected pound sign.\n" ); exit = true; return( false ); } dtmf.digits += obj.digit; if ( dtmf.digits.length >= digitmaxlength ) { exit = true; return( false ); } } } catch (e) { console_log( "err", e+"\n" ); } return( true ); } //end function mycb condition=true
I just made a new IVR with a recording made from the handset. (All previous IVRs were made using uploaded recordings and I wanted to see if that was a factor). The new IVR, 5010, when dialed from local extension 1001 now produces a "goodbye" response, while 5002-5005 still just produce a busy or fast busy signal.
-
It looks like you didn't add any options. So the IVR has nothing to do.
-
Fair enough. I thought it would play the recording even without actions.
So I added actions (and renumbered most of the IVRs) and when dialing any of the renumbered IVRs (i.e, any IVR other than the original 5000) I heard "goodbye".
Then I went to the status tab and hit the Reload XML button. Now when I dial any IVR other than 5000 I just get the busy signal.
Here's one with actions set. This is IVR 5010. It refers to IVRs 5000, 5010, 5012-5014, which have all been created with actions.
$ cat /usr/local/freeswitch/scripts/ivr_B18546C4-DCDC-5915-8C9F-047E6F8AA587.js var condition = true; var domain = "burgess.myphotos.cc"; //by default this is the ipv4 address of FreeSWITCH used for transfer to voicemail var digitmaxlength = 0; var objdate = new Date(); var adjusthours = 0; //Adjust Server time that is set to GMT 7 hours var adjustoperator = "-"; //+ or - if (adjustoperator == "-") { var objdate2 = new Date(objdate.getFullYear(),objdate.getMonth(),objdate.getDate(),(objdate.getHours() - adjusthours),objdate.getMinutes(),objdate.getSeconds()); } if (adjustoperator == "+") { var objdate2 = new Date(objdate.getFullYear(),objdate.getMonth(),objdate.getDate(),(objdate.getHours() + adjusthours),objdate.getMinutes(),objdate.getSeconds()); } var Hours = objdate2.getHours(); var Mins = objdate2.getMinutes(); var Seconds = objdate2.getSeconds(); var Month = objdate2.getMonth() + 1; var Date = objdate2.getDate(); var Year = objdate2.getYear() var Day = objdate2.getDay()+1; var exit = false; //console_log( "info", "IVR Server Time is: "+Hours+":"+Mins+" \n" ); function mycb( session, type, obj, arg ) { try { if ( type == "dtmf" ) { console_log( "info", "digit: "+obj.digit+"\n" ); if ( obj.digit == "#" ) { //console_log( "info", "detected pound sign.\n" ); exit = true; return( false ); } dtmf.digits += obj.digit; if ( dtmf.digits.length >= digitmaxlength ) { exit = true; return( false ); } } } catch (e) { console_log( "err", e+"\n" ); } return( true ); } //end function mycb condition=true if (condition) { //action //console_log( "info", "action call now don't wait for dtmf\n" ); var dtmf = new Object( ); dtmf.digits = ""; if ( session.ready( ) ) { session.answer( ); digitmaxlength = 1; while (session.ready() && ! exit ) { //session.streamFile( "C:/Program Files/FreeSWITCH/sounds/CityList.wav", mycb, "dtmf 10" ); session.streamFile( "/usr/local/freeswitch/recordings/CityList.wav", mycb, "dtmf 10" ); if (session.ready()) { if (dtmf.digits == 0) { dtmf.digits += session.getDigits(1, "#", 10000); // 10 seconds if (dtmf.digits == 0) { session.execute("transfer", "5010 XML default"); //Timeout > repeat CityList } else { break; //dtmf found end the while loop } } } } //pickup the remaining digits dtmf.digits += session.getDigits(3, "#", 3000); //allow up to 4 digits if ( dtmf.digits.length > "0" ) { if ( dtmf.digits == "1" ) { //FairviewList IVR session.execute("transfer", "5011 XML default"); } else if ( dtmf.digits == "2" ) { //SpiritRiverList IVR session.execute("transfer", "5012 XML default"); } else if ( dtmf.digits == "3" ) { //SexsmithList IVR session.execute("transfer", "5013 XML default"); } else if ( dtmf.digits == "4" ) { //GrandePrairieList IVR session.execute("transfer", "5014 XML default"); } else if ( dtmf.digits == "*" ) { //Return to WiseWelcome ivr session.execute("transfer", "5000 XML default"); } else if ( dtmf.digits == "t" ) { //Timeout > repeat CityList session.execute("transfer", "5010 XML default"); } else { session.execute("transfer", dtmf.digits+" XML default"); } } } //end if session.ready }
edit: I should mention at this point that I have not tested the IVRs from an external call. So far I am just dialing them internally. This is perhaps significant because I am not able to call 1002 from 1001 internally, although incoming calls pass to 1002 seemingly fine.
I did try the IVR calling in before adding actions and I was disconnected when choosing an option that should have transfered to 5002+. I can't confirm whether that is the case now.
-
Suggestion: Make sure the context of each IVR is set to 'default'
I wasn't able to duplicate the problem. Please find me on #pfsense-freeswitch irc channel and I will work on resolving the IVR problem you are having.
-
A fresh install didn't fix this issue, but "adjust the dialplan 'default.xml' under name="Local_Extension" change the regular expression="^(10[01][0-9])$" to expression="^(\d{4})$"" did.
Funny how things start to come into focus after a while.