[Freeswitch-users] Message Playback Stops

Michael De Lorenzo delorenzodesign at gmail.com
Thu Feb 24 06:50:11 MSK 2011


Is there some place where I can get more detailed log information on this?
I thought that streamFile was a blocking operation (the next statement
wouldn't be executed until playback was completed), is that not the case?

Is there a difference in terms of performance with Freeswitch for Lua versus
SpiderMonkey?


Am I misreading the log?
>
>
> *2011-02-21 17:23:09.077014 [NOTICE] switch_cpp.cpp:1181 Playing file:
> /usr/local/freeswitch/*
> *recordings/messages/16c0f890_**c35e33c0_777973.wav*
> 2011-02-21 17:23:09.077014 [DEBUG] switch_ivr_play_say.c:1186 Codec
> Activated L16 at 8000hz 1 channels 20ms
> 2011-02-21 17:23:19.417631 [DEBUG] switch_ivr_play_say.c:1515 done playing
> file
> 2011-02-21 17:23:19.417631 [NOTICE] switch_cpp.cpp:1181 !!!!! Finished
> playing the file !!!!!
> 2011-02-21 17:23:19.417631 [INFO] switch_cpp.cpp:1181 Was VM detected? no
> 2011-02-21 17:23:19.417631 [NOTICE] switch_cpp.cpp:1181 Played the message
> at least once and checked for VM, we should be exiting the loop
>
> The messages like "finished playing" are log commands that are only
> available in the script after it's answered.
>
>
>
>
> On Wed, Feb 23, 2011 at 11:48 AM, Anthony Minessale <
> anthony.minessale at gmail.com> wrote:
>
>> Your logs also don't show anything else like the call being answered
>> or hungup or any other information.
>>
>> you probably need to add {ignore_early_media=true} to your dial string
>> so the message does not play while the call is not answered.
>>
>> if you are calling sofia/internal/foo at bar.com change it to
>> {ignore_early_media=true}sofia/internal/foo at bar.com
>>
>>
>>
>>
>> On Wed, Feb 23, 2011 at 10:39 AM, Michael De Lorenzo
>> <delorenzodesign at gmail.com> wrote:
>> > Maybe failure isn't the correct word.  Here's what happens:
>> >
>> > Call gets placed, recipient phone rings
>> > Call answered
>> > Check for VM
>> > If not VM, play the message back after short delay  <-- the message
>> doesn't
>> > play, the call hangs up (step 5), but the logs indicate that the message
>> > played
>> > Hangup
>> >
>> > As the log shows, it doesn't indicate that the message playback fails.
>> >
>> > On Wed, Feb 23, 2011 at 11:14 AM, Anthony Minessale
>> > <anthony.minessale at gmail.com> wrote:
>> >>
>> >> I am asking for description of what happens when it fails, How do you
>> >> know it's failing?
>> >> If it fails it would be logging errors.
>> >>
>> >>
>> >>
>> >>
>> >> On Wed, Feb 23, 2011 at 12:00 AM, Michael De Lorenzo
>> >> <delorenzodesign at gmail.com> wrote:
>> >> > I'm not sure where to check, but there's entries like this in
>> >> > freeswitch.log.2011-02-21-23-40-11.1
>> >> >
>> >> > 2011-02-21 17:22:53.157390 [NOTICE] mod_logfile.c:158 New log
>> started.
>> >> > 2011-02-21 17:22:53.157390 [NOTICE] switch_cpp.cpp:1181 Played the
>> >> > message
>> >> > at least once and checked for VM, we should be exiting the loop.
>> >> > 2011-02-21 17:22:53.157390 [NOTICE] switch_cpp.cpp:1181 *************
>> >> > SETTING SESSION VARIABLES ***************
>> >> > 2011-02-21 17:22:53.157390 [NOTICE] switch_cpp.cpp:1181 Session
>> >> > Variable[profile_id]: 1
>> >> > 2011-02-21 17:22:53.157390 [NOTICE] switch_cpp.cpp:1181 *************
>> >> > DONE
>> >> > SETTING SESSION VARIABLES ***********
>> >> > 2011-02-21 17:22:53.377395 [NOTICE] switch_cpp.cpp:1181 Playing file:
>> >> >
>> /usr/local/freeswitch/recordings/messages/16c0f890_c35e33c0_777973.wav
>> >> > 2011-02-21 17:22:53.377395 [DEBUG] switch_ivr_play_say.c:1186 Codec
>> >> > Activated L16 at 8000hz 1 channels 20ms
>> >> > 2011-02-21 17:23:03.717511 [DEBUG] switch_ivr_play_say.c:1515 done
>> >> > playing
>> >> > file
>> >> > 2011-02-21 17:23:03.717511 [NOTICE] switch_cpp.cpp:1181 !!!!!
>> Finished
>> >> > playing the file !!!!!
>> >> > 2011-02-21 17:23:03.717511 [INFO] switch_cpp.cpp:1181 Was VM
>> detected?
>> >> > no
>> >> > 2011-02-21 17:23:03.717511 [NOTICE] switch_cpp.cpp:1181 Played the
>> >> > message
>> >> > at least once and checked for VM, we should be exiting the loop.
>> >> > 2011-02-21 17:23:03.717511 [NOTICE] switch_cpp.cpp:1181 *************
>> >> > SETTING SESSION VARIABLES ***************
>> >> > 2011-02-21 17:23:03.717511 [NOTICE] switch_cpp.cpp:1181 Session
>> >> > Variable[profile_id]: 1
>> >> > 2011-02-21 17:23:03.717511 [NOTICE] switch_cpp.cpp:1181 *************
>> >> > DONE
>> >> > SETTING SESSION VARIABLES ***********
>> >> > 2011-02-21 17:23:03.937661 [NOTICE] switch_cpp.cpp:1181 Playing file:
>> >> >
>> /usr/local/freeswitch/recordings/messages/16c0f890_c35e33c0_777973.wav
>> >> > 2011-02-21 17:23:03.937661 [DEBUG] switch_ivr_play_say.c:1186 Codec
>> >> > Activated L16 at 8000hz 1 channels 20ms
>> >> > 2011-02-21 17:23:08.237260 [DEBUG] switch_ivr_play_say.c:1515 done
>> >> > playing
>> >> > file
>> >> > 2011-02-21 17:23:08.237260 [NOTICE] switch_cpp.cpp:1181 !!!!!
>> Finished
>> >> > playing the file !!!!!
>> >> > 2011-02-21 17:23:08.237260 [INFO] switch_cpp.cpp:1181 Was VM
>> detected?
>> >> > no
>> >> > 2011-02-21 17:23:08.237260 [NOTICE] switch_cpp.cpp:1181 Played the
>> >> > message
>> >> > at least once and checked for VM, we should be exiting the loop.
>> >> > 2011-02-21 17:23:08.237260 [NOTICE] switch_cpp.cpp:1181 *************
>> >> > SETTING SESSION VARIABLES ***************
>> >> > 2011-02-21 17:23:08.237260 [NOTICE] switch_cpp.cpp:1181 Session
>> >> > Variable[profile_id]: 1
>> >> > 2011-02-21 17:23:08.237260 [NOTICE] switch_cpp.cpp:1181 *************
>> >> > DONE
>> >> > SETTING SESSION VARIABLES ***********
>> >> > 2011-02-21 17:23:08.437885 [NOTICE] switch_cpp.cpp:1181 Playing file:
>> >> >
>> /usr/local/freeswitch/recordings/messages/16c0f890_c35e33c0_777973.wav
>> >> > 2011-02-21 17:23:08.437885 [DEBUG] switch_ivr_play_say.c:1186 Codec
>> >> > Activated L16 at 8000hz 1 channels 20ms
>> >> > 2011-02-21 17:23:08.857270 [DEBUG] switch_ivr_play_say.c:1515 done
>> >> > playing
>> >> > file
>> >> > 2011-02-21 17:23:08.857270 [NOTICE] switch_cpp.cpp:1181 !!!!!
>> Finished
>> >> > playing the file !!!!!
>> >> > 2011-02-21 17:23:08.857270 [INFO] switch_cpp.cpp:1181 Was VM
>> detected?
>> >> > no
>> >> > 2011-02-21 17:23:08.857270 [NOTICE] switch_cpp.cpp:1181 Played the
>> >> > message
>> >> > at least once and checked for VM, we should be exiting the loop.
>> >> > 2011-02-21 17:23:08.857270 [NOTICE] switch_cpp.cpp:1181 *************
>> >> > SETTING SESSION VARIABLES ***************
>> >> > 2011-02-21 17:23:08.857270 [NOTICE] switch_cpp.cpp:1181 Session
>> >> > Variable[profile_id]: 1
>> >> > 2011-02-21 17:23:08.857270 [NOTICE] switch_cpp.cpp:1181 *************
>> >> > DONE
>> >> > SETTING SESSION VARIABLES ***********
>> >> > 2011-02-21 17:23:09.077014 [NOTICE] switch_cpp.cpp:1181 Playing file:
>> >> >
>> /usr/local/freeswitch/recordings/messages/16c0f890_c35e33c0_777973.wav
>> >> > 2011-02-21 17:23:09.077014 [DEBUG] switch_ivr_play_say.c:1186 Codec
>> >> > Activated L16 at 8000hz 1 channels 20ms
>> >> > 2011-02-21 17:23:19.417631 [DEBUG] switch_ivr_play_say.c:1515 done
>> >> > playing
>> >> > file
>> >> > 2011-02-21 17:23:19.417631 [NOTICE] switch_cpp.cpp:1181 !!!!!
>> Finished
>> >> > playing the file !!!!!
>> >> > 2011-02-21 17:23:19.417631 [INFO] switch_cpp.cpp:1181 Was VM
>> detected?
>> >> > no
>> >> > 2011-02-21 17:23:19.417631 [NOTICE] switch_cpp.cpp:1181 Played the
>> >> > message
>> >> > at least once and checked for VM, we should be exiting the loop.
>> >> >
>> >> > I also have the Freeswitch log from the date too, but I'm not sure
>> what
>> >> > I
>> >> > should post here that would be useful.
>> >> >
>> >> >
>> >> >
>> >> > On Tue, Feb 22, 2011 at 8:20 PM, Anthony Minessale
>> >> > <anthony.minessale at gmail.com> wrote:
>> >> >>
>> >> >> do you have any console logs of it failing or any error messages
>> etc?
>> >> >>
>> >> >>
>> >> >> On Tue, Feb 22, 2011 at 1:22 AM, Michael De Lorenzo
>> >> >> <delorenzodesign at gmail.com> wrote:
>> >> >> > Hello,
>> >> >> >
>> >> >> > I have a Freeswitch installation that is intended to make many
>> calls
>> >> >> > (thousands) and playback a single wav file.  The calls are
>> >> >> > successfully
>> >> >> > processed (the recipient's phone rings), but the call almost
>> >> >> > immediately
>> >> >> > disconnects, after about 1s.  Everything seems to work fine if I'm
>> >> >> > only
>> >> >> > pushing one or two calls through the Freeswitch instance, but as
>> soon
>> >> >> > as
>> >> >> > I
>> >> >> > turn up the call rate (I'm still only doing about 50 concurrent
>> >> >> > sessions)
>> >> >> > the playback begins to fail.
>> >> >> >
>> >> >> > I've watched the calls go out from the console and nothing looks
>> out
>> >> >> > of
>> >> >> > the
>> >> >> > ordinary, except that the calls are disconnected with NORMAL
>> CLEARING
>> >> >> > prior
>> >> >> > to completion.
>> >> >> >
>> >> >> > Here's the Lua script I'm using...
>> >> >> >
>> >> >> > profile_id = argv[1];
>> >> >> > account_code = argv[2];
>> >> >> > client_id = argv[3];
>> >> >> > caller_id_name = argv[4];
>> >> >> > caller_id = argv[5];
>> >> >> > dial_id = argv[6];
>> >> >> > number_to_call = argv[7];
>> >> >> > message_to_play = argv[8];
>> >> >> > max_retries = argv[9];
>> >> >> > retry_interval = argv[10];
>> >> >> >
>> >> >> > local human_detected = false
>> >> >> > local voicemail_detected = false;
>> >> >> > local message_played = false;
>> >> >> >
>> >> >> > recordings_directory =
>> "/usr/local/freeswitch/recordings/messages/";
>> >> >> >
>> >> >> > function setDialVariables(set_as_session_variables)
>> >> >> >     local s = "profile_id=" .. profile_id;
>> >> >> >     s = s .. ",account_code=" .. account_code;
>> >> >> >     s = s .. ",client_id=" .. client_id;
>> >> >> >     s = s .. ",caller_id_name=" .. caller_id_name;
>> >> >> >     s = s .. ",caller_id=" .. caller_id;
>> >> >> >     s = s .. ",dial_id=" .. dial_id;
>> >> >> >     s = s .. ",number_to_call=" .. number_to_call;
>> >> >> >     s = s .. ",message_to_play=" .. message_to_play;
>> >> >> >
>> >> >> >     freeswitch.consoleLog("notice", s .. "\n");
>> >> >> >
>> >> >> >     return s
>> >> >> > end
>> >> >> >
>> >> >> > function printSessionVariables()
>> >> >> >     freeswitch.consoleLog("notice", "******* PRINTING SESSION
>> >> >> > VARIABLES
>> >> >> > **********\n");
>> >> >> >     -- ommitted
>> >> >> >     freeswitch.consoleLog("notice",
>> >> >> > "**********************************************\n");
>> >> >> > end
>> >> >> >
>> >> >> > function onInput(s, type, obj, arg)
>> >> >> >     if(type == "event" and voicemail_detected == false) then
>> >> >> >         freeswitch.consoleLog("debug","************ VOICE
>> >> >> > MAIL/ANSWERING
>> >> >> > MACHINE DETECTED *************\n");
>> >> >> >         voicemail_detected = true;
>> >> >> >         return "break";
>> >> >> >     end
>> >> >> >     return true;
>> >> >> > end
>> >> >> >
>> >> >> > function playbackMessage(sleepTime)
>> >> >> >     message_played = false;
>> >> >> >     session:sleep(sleepTime);
>> >> >> >     -- play a file
>> >> >> >     message_file = recordings_directory .. message_to_play;
>> >> >> >     freeswitch.consoleLog("notice", "Playing file: " ..
>> message_file
>> >> >> > ..
>> >> >> > "\n");
>> >> >> >     session:streamFile(message_file);
>> >> >> >     freeswitch.consoleLog("notice", "!!!!! Finished playing the
>> file
>> >> >> > !!!!!\n");
>> >> >> >     message_played = true;
>> >> >> > end
>> >> >> >
>> >> >> > session = freeswitch.Session("{" .. setDialVariables(false) ..
>> >> >> > ",ignore_early_media=true,origination_caller_id_name=" ..
>> >> >> > caller_id_name
>> >> >> > ..
>> >> >> > ",origination_caller_id_number=+1" .. caller_id ..
>> >> >> > "}sofia/gateway/gateway_"
>> >> >> > .. profile_id .. "/" .. number_to_call);
>> >> >> >
>> >> >> > while(session:ready()) do
>> >> >> >    setDialVariables(true)
>> >> >> >    session:answer();
>> >> >> >
>> >> >> >    -- session:execute("continue_on_fail","true");
>> >> >> >    session:setInputCallback("onInput","true");
>> >> >> >    session:execute("avmd","start");
>> >> >> >
>> >> >> >    playbackMessage(200);
>> >> >> >
>> >> >> >    vm_status = voicemail_detected == true and "yes" or "no"
>> >> >> >    freeswitch.consoleLog("info", "Was VM detected? " .. vm_status
>> ..
>> >> >> > "\n");
>> >> >> >    if(voicemail_detected) then
>> >> >> >       return "break";
>> >> >> >    end
>> >> >> >
>> >> >> >    freeswitch.consoleLog("notice", "Played the message at least
>> once
>> >> >> > and
>> >> >> > checked for VM, we should be exiting the loop.\n")
>> >> >> > end
>> >> >> >
>> >> >> > if (voicemail_detected) then
>> >> >> >     freeswitch.consoleLog("info", "Playback for voicemail.\n");
>> >> >> >     session:execute("avmd","stop");
>> >> >> >     playbackMessage(5000);
>> >> >> > end
>> >> >> >
>> >> >> > freeswitch.consoleLog("info", "All finished, hanging up the
>> >> >> > session.\n");
>> >> >> > session:hangup();
>> >> >> >
>> >> >> > Any help would be greatly appreciated.
>> >> >> >
>> >> >> > Thank you,
>> >> >> >
>> >> >> > Michael
>> >> >> >
>> >> >> > _______________________________________________
>> >> >> > 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/
>> >> >> Twitter: http://twitter.com/FreeSWITCH_wire
>> >> >>
>> >> >> AIM: anthm
>> >> >> MSN:anthony_minessale at hotmail.com
>> >> >> GTALK/JABBER/PAYPAL:anthony.minessale at gmail.com
>> >> >> IRC: irc.freenode.net #freeswitch
>> >> >>
>> >> >> FreeSWITCH Developer Conference
>> >> >> sip:888 at conference.freeswitch.org
>> >> >> googletalk:conf+888 at conference.freeswitch.org
>> >> >> pstn:+19193869900
>> >> >
>> >> >
>> >>
>> >>
>> >>
>> >> --
>> >> Anthony Minessale II
>> >>
>> >> FreeSWITCH http://www.freeswitch.org/
>> >> ClueCon http://www.cluecon.com/
>> >> Twitter: http://twitter.com/FreeSWITCH_wire
>> >>
>> >> AIM: anthm
>> >> MSN:anthony_minessale at hotmail.com
>> >> GTALK/JABBER/PAYPAL:anthony.minessale at gmail.com
>> >> IRC: irc.freenode.net #freeswitch
>> >>
>> >> FreeSWITCH Developer Conference
>> >> sip:888 at conference.freeswitch.org
>> >> googletalk:conf+888 at conference.freeswitch.org
>> >> pstn:+19193869900
>> >
>> >
>>
>>
>>
>> --
>> Anthony Minessale II
>>
>> FreeSWITCH http://www.freeswitch.org/
>> ClueCon http://www.cluecon.com/
>> Twitter: http://twitter.com/FreeSWITCH_wire
>>
>> AIM: anthm
>> MSN:anthony_minessale at hotmail.com
>> GTALK/JABBER/PAYPAL:anthony.minessale at gmail.com
>> IRC: irc.freenode.net #freeswitch
>>
>> FreeSWITCH Developer Conference
>> sip:888 at conference.freeswitch.org
>> googletalk:conf+888 at conference.freeswitch.org
>> pstn:+19193869900
>>
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20110223/1ae04d4d/attachment-0001.html 


More information about the FreeSWITCH-users mailing list