Message: 5 Date: Tue, 14 Jul 2009 06:00:10 -0700 From: Michael S Collins <[email protected]> Subject: Re: [Freeswitch-users] Get voicemail messages To: "[email protected]" <[email protected]> Message-ID: <[email protected]> Content-Type: text/plain; charset=us-ascii; format=flowed; delsp=yes
On Jul 14, 2009, at 5:02 AM, Eli Hayun <[email protected]> wrote: > > Hi > > I am not using fixed xml files for the extension registration. I have > > LUA script to return an XML string to FS. > > Everything goes fine until I am trying to get the voice messages. > > When am entering my id, FS (or voicemail module) try to get the xml > > for > > that id, but it cant find it. My lua script did NOT recieved any xml > > request at that point. > > What should I do to solve the problem. > > > > Thanks > > Eli Hayun > Can you pastebin the log? Be sure to press F8 to turn up the debug level. Here is the log ( with the XML string for the requested id (80670) freeswi...@tst-sip-srv> API CALL [console(loglevel 7)] output: +OK console log level set to DEBUG freeswi...@tst-sip-srv> 2009-07-14 16:05:15.860230 [DEBUG] sofia.c:4554 IP 132.64.4.238 Rejected by acl "domains". Falling back to Digest auth. 2009-07-14 16:05:16.88367 [DEBUG] sofia.c:4554 IP 132.64.4.238 Rejected by acl "domains". Falling back to Digest auth. -> <?xml version="1.0" encoding="UTF-8" standalone="no"?> <document type="freeswitch/xml"> <section name="directory" description="Huji Directory"> <domain name="132.64.3.86"> <params> <param name="dial-string" value="{presence_id=${dialed_us...@${dialed_domain}}${sofia_contact(${dialed_us...@${dialed_domain})}"/> </params> <user id="80670" mailbox="80670"\> <params> <param name="password" value="ph1pwd"/> <param name="vm-password" value="8670"/> <param name="vm-mailto" value="[email protected]"/> <param name="vm-email-all-messages" value="true"/> <param name="vm-attach-file" value="true"/> </params> <variables> <variable name="accountcode" value="80670"/> <variable name="user_context" value="default"/> <variable name="max_calls" value="1"/> <variable name="effective_caller_id_name" value="n0 l0"/> </variables> </user> </domain> </section> </document> <-- 2009-07-14 16:05:16.108310 [NOTICE] switch_channel.c:602 New Channel sofia/internal/[email protected] [f9716554-7076-11de-9237-7d312efadfc4] 2009-07-14 16:05:16.112125 [DEBUG] sofia.c:3215 Channel sofia/internal/[email protected] entering state [received][100] 2009-07-14 16:05:16.112125 [DEBUG] switch_core_state_machine.c:397 (sofia/internal/[email protected]) Running State Change CS_NEW 2009-07-14 16:05:16.112125 [DEBUG] sofia.c:3222 Remote SDP: v=0 o=root 1385664886 1385664886 IN IP4 132.64.4.238 s=call c=IN IP4 132.64.4.238 t=0 0 m=audio 57682 RTP/AVP 0 8 9 99 3 18 4 101 a=rtpmap:0 pcmu/8000 a=rtpmap:8 pcma/8000 a=rtpmap:9 g722/8000 a=rtpmap:99 g726-32/8000 a=rtpmap:3 gsm/8000 a=rtpmap:18 g729/8000 a=rtpmap:4 g723/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=direction:both a=ptime:20 2009-07-14 16:05:16.112125 [DEBUG] sofia_glue.c:3070 Audio Codec Compare [pcmu:0:8000:20]/[G7221:115:32000:20] 2009-07-14 16:05:16.112125 [DEBUG] sofia_glue.c:3070 Audio Codec Compare [pcmu:0:8000:20]/[G7221:107:16000:20] 2009-07-14 16:05:16.112125 [DEBUG] sofia_glue.c:3070 Audio Codec Compare [pcmu:0:8000:20]/[G722:9:8000:20] 2009-07-14 16:05:16.112125 [DEBUG] sofia_glue.c:3070 Audio Codec Compare [pcmu:0:8000:20]/[PCMU:0:8000:20] 2009-07-14 16:05:16.112125 [DEBUG] sofia_glue.c:2028 Set Codec sofia/internal/[email protected] PCMU/8000 20 ms 160 samples 2009-07-14 16:05:16.112125 [DEBUG] sofia_glue.c:3030 Set 2833 dtmf payload to 101 2009-07-14 16:05:16.112125 [DEBUG] switch_core_state_machine.c:403 (sofia/internal/[email protected]) State NEW 2009-07-14 16:05:16.112125 [DEBUG] sofia.c:3381 (sofia/internal/[email protected]) State Change CS_NEW -> CS_INIT 2009-07-14 16:05:16.112125 [DEBUG] switch_core_session.c:933 Send signal sofia/internal/[email protected] [BREAK] 2009-07-14 16:05:16.112125 [DEBUG] switch_core_state_machine.c:397 (sofia/internal/[email protected]) Running State Change CS_INIT 2009-07-14 16:05:16.116244 [DEBUG] switch_core_state_machine.c:480 (sofia/internal/[email protected]) State INIT 2009-07-14 16:05:16.116244 [DEBUG] mod_sofia.c:83 sofia/internal/[email protected] SOFIA INIT 2009-07-14 16:05:16.116244 [DEBUG] mod_sofia.c:111 (sofia/internal/[email protected]) State Change CS_INIT -> CS_ROUTING 2009-07-14 16:05:16.116244 [DEBUG] switch_core_session.c:933 Send signal sofia/internal/[email protected] [BREAK] 2009-07-14 16:05:16.116244 [DEBUG] switch_core_state_machine.c:480 (sofia/internal/[email protected]) State INIT going to sleep 2009-07-14 16:05:16.116244 [DEBUG] switch_core_state_machine.c:397 (sofia/internal/[email protected]) Running State Change CS_ROUTING 2009-07-14 16:05:16.116244 [DEBUG] switch_core_state_machine.c:483 (sofia/internal/[email protected]) State ROUTING 2009-07-14 16:05:16.116244 [DEBUG] mod_sofia.c:130 sofia/internal/[email protected] SOFIA ROUTING 2009-07-14 16:05:16.116244 [DEBUG] switch_core_state_machine.c:78 sofia/internal/[email protected] Standard ROUTING 2009-07-14 16:05:16.116244 [INFO] mod_dialplan_xml.c:252 Processing phone-1->*98 in context default Dialplan: sofia/internal/[email protected] parsing [default->unloop] continue=false Dialplan: sofia/internal/[email protected] Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: sofia/internal/[email protected] Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: sofia/internal/[email protected] parsing [default->tod_example] continue=true Dialplan: sofia/internal/[email protected] Regex (PASS) [tod_example] ${strftime(%w)}(2) =~ /^([1-5])$/ break=on-false Dialplan: sofia/internal/[email protected] Regex (PASS) [tod_example] ${strftime(%H%M)}(1605) =~ /^((09|1[0-7])[0-5][0-9]|1800)$/ break=on-false Dialplan: sofia/internal/[email protected] Action set(open=true) Dialplan: sofia/internal/[email protected] parsing [default->global-intercept] continue=false Dialplan: sofia/internal/[email protected] Regex (FAIL) [global-intercept] destination_number(*98) =~ /^886$/ break=on-false Dialplan: sofia/internal/[email protected] parsing [default->group-intercept] continue=false Dialplan: sofia/internal/[email protected] Regex (FAIL) [group-intercept] destination_number(*98) =~ /^\*8$/ break=on-false Dialplan: sofia/internal/[email protected] parsing [default->intercept-ext] continue=false Dialplan: sofia/internal/[email protected] Regex (FAIL) [intercept-ext] destination_number(*98) =~ /^\*\*(\d+)$/ break=on-false Dialplan: sofia/internal/[email protected] parsing [default->redial] continue=false Dialplan: sofia/internal/[email protected] Regex (FAIL) [redial] destination_number(*98) =~ /^870$/ break=on-false Dialplan: sofia/internal/[email protected] parsing [default->global] continue=true Dialplan: sofia/internal/[email protected] Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never Dialplan: sofia/internal/[email protected] Regex (FAIL) [global] ${sip_has_crypto}() =~ /^(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)$/ break=never Dialplan: sofia/internal/[email protected] Absolute Condition [global] Dialplan: sofia/internal/[email protected] Action hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid}) Dialplan: sofia/internal/[email protected] Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number}) Dialplan: sofia/internal/[email protected] Action hash(insert/${domain_name}-last_dial/global/${uuid}) Dialplan: sofia/internal/[email protected] parsing [default->snom-demo-2] continue=false Dialplan: sofia/internal/[email protected] Regex (FAIL) [snom-demo-2] destination_number(*98) =~ /^9001$/ break=on-false Dialplan: sofia/internal/[email protected] parsing [default->snom-demo-1] continue=false Dialplan: sofia/internal/[email protected] Regex (FAIL) [snom-demo-1] destination_number(*98) =~ /^9000$/ break=on-false Dialplan: sofia/internal/[email protected] parsing [default->eavesdrop] continue=false Dialplan: sofia/internal/[email protected] Regex (FAIL) [eavesdrop] destination_number(*98) =~ /^88(.*)$|^\*0(.*)$/ break=on-false Dialplan: sofia/internal/[email protected] parsing [default->eavesdrop] continue=false Dialplan: sofia/internal/[email protected] Regex (FAIL) [eavesdrop] destination_number(*98) =~ /^779$/ break=on-false Dialplan: sofia/internal/[email protected] parsing [default->call_return] continue=false Dialplan: sofia/internal/[email protected] Regex (FAIL) [call_return] destination_number(*98) =~ /^\*69$|^869$|^lcr$/ break=on-false Dialplan: sofia/internal/[email protected] parsing [default->del-group] continue=false Dialplan: sofia/internal/[email protected] Regex (FAIL) [del-group] destination_number(*98) =~ /^80(\d{2})$/ break=on-false Dialplan: sofia/internal/[email protected] parsing [default->add-group] continue=false Dialplan: sofia/internal/[email protected] Regex (FAIL) [add-group] destination_number(*98) =~ /^81(\d{2})$/ break=on-false Dialplan: sofia/internal/[email protected] parsing [default->call-group-simo] continue=false Dialplan: sofia/internal/[email protected] Regex (FAIL) [call-group-simo] destination_number(*98) =~ /^82(\d{2})$/ break=on-false Dialplan: sofia/internal/[email protected] parsing [default->call-group-order] continue=false Dialplan: sofia/internal/[email protected] Regex (FAIL) [call-group-order] destination_number(*98) =~ /^83(\d{2})$/ break=on-false Dialplan: sofia/internal/[email protected] parsing [default->extension-intercom] continue=false Dialplan: sofia/internal/[email protected] Regex (FAIL) [extension-intercom] destination_number(*98) =~ /^(8888)$/ break=on-false Dialplan: sofia/internal/[email protected] parsing [default->Local_Extension] continue=false Dialplan: sofia/internal/[email protected] Regex (FAIL) [Local_Extension] destination_number(*98) =~ /^(80\d{3})$/ break=on-false Dialplan: sofia/internal/[email protected] parsing [default->group_dial_sales] continue=false Dialplan: sofia/internal/[email protected] Regex (FAIL) [group_dial_sales] destination_number(*98) =~ /^2000$/ break=on-false Dialplan: sofia/internal/[email protected] parsing [default->group_dial_support] continue=false Dialplan: sofia/internal/[email protected] Regex (FAIL) [group_dial_support] destination_number(*98) =~ /^2001$/ break=on-false Dialplan: sofia/internal/[email protected] parsing [default->group_dial_billing] continue=false Dialplan: sofia/internal/[email protected] Regex (FAIL) [group_dial_billing] destination_number(*98) =~ /^2002$/ break=on-false Dialplan: sofia/internal/[email protected] parsing [default->operator] continue=false Dialplan: sofia/internal/[email protected] Regex (FAIL) [operator] destination_number(*98) =~ /^(operator|0)$/ break=on-false Dialplan: sofia/internal/[email protected] parsing [default->vmain] continue=false Dialplan: sofia/internal/[email protected] Regex (PASS) [vmain] destination_number(*98) =~ /^vmain$|^86111$|^\*98$/ break=on-false Dialplan: sofia/internal/[email protected] Action answer() Dialplan: sofia/internal/[email protected] Action sleep(1000) Dialplan: sofia/internal/[email protected] Action voicemail(check default ${domain_name} ${caller_id_number}) 2009-07-14 16:05:16.120891 [DEBUG] switch_core_state_machine.c:114 (sofia/internal/[email protected]) State Change CS_ROUTING -> CS_EXECUTE 2009-07-14 16:05:16.120891 [DEBUG] switch_core_session.c:933 Send signal sofia/internal/[email protected] [BREAK] 2009-07-14 16:05:16.120891 [DEBUG] switch_core_state_machine.c:483 (sofia/internal/[email protected]) State ROUTING going to sleep 2009-07-14 16:05:16.120891 [DEBUG] switch_core_state_machine.c:397 (sofia/internal/[email protected]) Running State Change CS_EXECUTE 2009-07-14 16:05:16.120891 [DEBUG] switch_core_state_machine.c:490 (sofia/internal/[email protected]) State EXECUTE 2009-07-14 16:05:16.120891 [DEBUG] mod_sofia.c:173 sofia/internal/[email protected] SOFIA EXECUTE 2009-07-14 16:05:16.120891 [DEBUG] switch_core_state_machine.c:151 sofia/internal/[email protected] Standard EXECUTE EXECUTE sofia/internal/[email protected] set(open=true) 2009-07-14 16:05:16.120891 [DEBUG] mod_dptools.c:748 sofia/internal/[email protected] SET [open]=[true] EXECUTE sofia/internal/[email protected] hash(insert/132.64.3.86-spymap/80670/f9716554-7076-11de-9237-7d312efadfc4) EXECUTE sofia/internal/[email protected] hash(insert/132.64.3.86-last_dial/80670/*98) EXECUTE sofia/internal/[email protected] hash(insert/132.64.3.86-last_dial/global/f9716554-7076-11de-9237-7d312efadfc4) EXECUTE sofia/internal/[email protected] answer() 2009-07-14 16:05:16.124221 [DEBUG] mod_dptools.c:649 sofia/internal/[email protected] receive message [ANSWER] 2009-07-14 16:05:16.124221 [DEBUG] sofia_glue.c:2262 AUDIO RTP [sofia/internal/[email protected]] 132.64.3.86 port 31372 -> 132.64.4.238 port 57682 codec: 0 ms: 20 2009-07-14 16:05:16.124221 [DEBUG] switch_rtp.c:1138 Starting timer [soft] 160 bytes per 20ms 2009-07-14 16:05:16.138142 [DEBUG] mod_sofia.c:549 Local SDP sofia/internal/[email protected]: v=0 o=FreeSWITCH 1247545344 1247545345 IN IP4 132.64.3.86 s=FreeSWITCH c=IN IP4 132.64.3.86 t=0 0 m=audio 31372 RTP/AVP 0 101 a=rtpmap:0 pcmu/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv 2009-07-14 16:05:16.138142 [DEBUG] switch_core_session.c:630 Send signal sofia/internal/[email protected] [BREAK] 2009-07-14 16:05:16.138142 [NOTICE] mod_dptools.c:649 Channel [sofia/internal/[email protected]] has been answered 2009-07-14 16:05:16.138142 [DEBUG] switch_channel.c:182 sofia/internal/[email protected] receive message [AUDIO_SYNC] EXECUTE sofia/internal/[email protected] sleep(1000) 2009-07-14 16:05:16.138142 [DEBUG] switch_channel.c:182 sofia/internal/[email protected] receive message [AUDIO_SYNC] 2009-07-14 16:05:16.138142 [DEBUG] sofia.c:3215 Channel sofia/internal/[email protected] entering state [completed][200] 2009-07-14 16:05:16.216623 [DEBUG] sofia.c:3215 Channel sofia/internal/[email protected] entering state [ready][200] EXECUTE sofia/internal/[email protected] voicemail(check default 132.64.3.86 80670) 2009-07-14 16:05:17.148904 [DEBUG] mod_voicemail.c:776 [default] rwlock 2009-07-14 16:05:17.148904 [DEBUG] switch_ivr_play_say.c:118 No language specified - Using [en] 2009-07-14 16:05:17.152174 [DEBUG] switch_ivr_play_say.c:273 Handle play-file:[voicemail/vm-hello.wav] (en:en) 2009-07-14 16:05:17.152174 [DEBUG] switch_ivr_play_say.c:1097 Codec Activated l...@8000hz 1 channels 20ms 2009-07-14 16:05:17.152174 [DEBUG] switch_core_io.c:649 sofia/internal/[email protected] receive message [TRANSCODING_NECESSARY] 2009-07-14 16:05:18.368781 [DEBUG] switch_ivr_play_say.c:1391 done playing file 2009-07-14 16:05:18.488598 [DEBUG] switch_channel.c:182 sofia/internal/[email protected] receive message [AUDIO_SYNC] 2009-07-14 16:05:18.608382 [DEBUG] switch_channel.c:182 sofia/internal/[email protected] receive message [AUDIO_SYNC] 2009-07-14 16:05:18.708720 [WARNING] mod_voicemail.c:2072 Can't find user [[email protected]] 2009-07-14 16:05:18.708720 [DEBUG] switch_ivr_play_say.c:118 No language specified - Using [en] 2009-07-14 16:05:18.712630 [DEBUG] switch_ivr_play_say.c:273 Handle play-file:[voicemail/vm-goodbye.wav] (en:en) 2009-07-14 16:05:18.712630 [DEBUG] switch_ivr_play_say.c:1097 Codec Activated l...@8000hz 1 channels 20ms 2009-07-14 16:05:18.712630 [DEBUG] switch_core_io.c:649 sofia/internal/[email protected] receive message [TRANSCODING_NECESSARY] 2009-07-14 16:05:19.188996 [DEBUG] switch_ivr_play_say.c:1391 done playing file 2009-07-14 16:05:19.308974 [NOTICE] switch_core_state_machine.c:179 Hangup sofia/internal/[email protected] [CS_EXECUTE] [NORMAL_CLEARING] 2009-07-14 16:05:19.308974 [DEBUG] switch_channel.c:1683 Send signal sofia/internal/[email protected] [KILL] 2009-07-14 16:05:19.308974 [DEBUG] switch_core_session.c:933 Send signal sofia/internal/[email protected] [BREAK] 2009-07-14 16:05:19.308974 [DEBUG] switch_core_state_machine.c:490 (sofia/internal/[email protected]) State EXECUTE going to sleep 2009-07-14 16:05:19.308974 [DEBUG] switch_core_state_machine.c:397 (sofia/internal/[email protected]) Running State Change CS_HANGUP 2009-07-14 16:05:19.308974 [DEBUG] switch_core_state_machine.c:433 (sofia/internal/[email protected]) State HANGUP 2009-07-14 16:05:19.308974 [DEBUG] mod_sofia.c:338 Channel sofia/internal/[email protected] hanging up, cause: NORMAL_CLEARING 2009-07-14 16:05:19.308974 [DEBUG] mod_sofia.c:393 Sending BYE to sofia/internal/[email protected] 2009-07-14 16:05:19.312163 [DEBUG] switch_core_state_machine.c:46 sofia/internal/[email protected] Standard HANGUP, cause: NORMAL_CLEARING 2009-07-14 16:05:19.312163 [DEBUG] switch_core_state_machine.c:433 (sofia/internal/[email protected]) State HANGUP going to sleep 2009-07-14 16:05:19.312163 [DEBUG] switch_core_state_machine.c:475 (sofia/internal/[email protected]) State Change CS_HANGUP -> CS_REPORTING 2009-07-14 16:05:19.312163 [DEBUG] switch_core_session.c:933 Send signal sofia/internal/[email protected] [BREAK] 2009-07-14 16:05:19.312163 [DEBUG] switch_core_state_machine.c:397 (sofia/internal/[email protected]) Running State Change CS_REPORTING 2009-07-14 16:05:19.312163 [DEBUG] switch_core_state_machine.c:607 (sofia/internal/[email protected]) State REPORTING 2009-07-14 16:05:19.312163 [DEBUG] switch_core_state_machine.c:53 sofia/internal/[email protected] Standard REPORTING, cause: NORMAL_CLEARING 2009-07-14 16:05:19.312163 [DEBUG] switch_core_state_machine.c:607 (sofia/internal/[email protected]) State REPORTING going to sleep 2009-07-14 16:05:19.312163 [DEBUG] switch_core_state_machine.c:410 (sofia/internal/[email protected]) State Change CS_REPORTING -> CS_DESTROY 2009-07-14 16:05:19.312163 [DEBUG] switch_core_session.c:1067 Session 7 (sofia/internal/[email protected]) Locked, Waiting on external entities 2009-07-14 16:05:19.312163 [NOTICE] switch_core_session.c:1085 Session 7 (sofia/internal/[email protected]) Ended 2009-07-14 16:05:19.312163 [NOTICE] switch_core_session.c:1087 Close Channel sofia/internal/[email protected] [CS_DESTROY] 2009-07-14 16:05:19.312163 [DEBUG] switch_core_state_machine.c:559 (sofia/internal/[email protected]) State DESTROY 2009-07-14 16:05:19.312163 [DEBUG] mod_sofia.c:255 sofia/internal/[email protected] SOFIA DESTROY 2009-07-14 16:05:19.312163 [DEBUG] switch_core_state_machine.c:60 sofia/internal/[email protected] Standard DESTROY 2009-07-14 16:05:19.312163 [DEBUG] switch_core_state_machine.c:559 (sofia/internal/[email protected]) State DESTROY going to sleep - Thanks Eli Hayun _______________________________________________ Freeswitch-users mailing list [email protected] http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
