November 2012 - FreeSWITCH-users - FreeSWITCH Mailing Lists

retreiving voicemail dropping after 30 seconds
by Jason Holden 19 Nov '12

19 Nov '12

Hi. When accessing voicemail to listen to messages I am finding that it is dropping at 30 seconds each time with a message of 100 sleep timer. Does anyone have any recommendations? I am using a Sipura 3000 connected to my freeswitch server.

2 1

changing vm default announcement
by andy 19 Nov '12

19 Nov '12

Hi all, I am trying to change the default greeting that plays to the caller from the standard voicemail/callie when the call is not answered.. I have not been able to find where the script is for the ivr that answers the call. I tried overriding the default in the dialplan by using : <action application="set" data="voicemail_greeting_number=1"/> <action application="set" data="skip_instructions=true"/> but this did not change anything - the default greeting still plays. I have tried to copy a different message into each user's directory as greeting_1.wav, but some flag is not been set so callie still plays Any suggestions? drew

4 4

extension name="Your_Are_Here"
by Scott 19 Nov '12

19 Nov '12

In the dialplan xml, for the <extension name="You_Are_Here" > clause, how does one reference the value of the name= ? e.g. <action application="log" data="INFO this message emitted from [${name}]" /> It's in the debug output so it "in there somewhere." :-) With thanks,

2 1

Suggestion to harmonize 'hash' & 'db' insert method
by Scott 19 Nov '12

19 Nov '12

Are there reasons why the function 'hash' (non-persistent storage) and function 'db' (persistent storage) share a look-a-like user interface (e.g. select/insert/delete) but do not work-a-like. In particular, in 'hash', insert overwrites an identical realm/data_key pair whereas 'db' , in so far as I can tell, just blindly adds, and adds, adds, the insert(s). However, the 'db' select method returns one record only even if the db has accumulated many realm/data_key records, including data_value duplicates. NOTWITHSTANDING reasons-unknow-to-me, a remedy to harmonize the non-persistent 'hash' with the persistent 'db' I *think* is straight forward ... (1) At the call_limit.db schema-level, a one-time create UNIQUE COMPOUND index, as follows, CREATE UNIQUE INDEX IF NOT EXISTS 'idx_db_data_HostRealmDK' ON 'db_data' ('hostname','realm','data_key'); (1) At the c-language embedded SQL string-level, change the existing INSERT to be the following, INSERT OR REPLACE INTO db_data (hostname,realm,data_key,data) VALUES (%s,%s,%s,%s); The index will help speed UP the reads. Neither change is "exotic" and should be portable across standard sql implementations. ;-) ... thoughts ? Thanks,

6 9

problem with receiving and sending faxes
by sterned 19 Nov '12

19 Nov '12

Hello Please help me with the fax. I created a user 500 and 501. created a dialplan for 500 and am trying to send a fax from the server command: freeswitch @ internal> originate loopback/500 & txfax (/ tmp / txfax-sample.tiff) use: soft fax Venta Fax&Voice dialplan: <extension name="fax"> <condition> <action application="set" data="fax_enable_t38=true"/> <action application="set" data="execute_on_answer=t38_gateway self"/> <action application="set" data="proxy_media=true" /> <action application="bridge" data="user/500(a)192.168.13.18"/> </condition> </extension> log: freeswitch@internal> originate loopback/500 &txfax(/tmp/txfax-sample.tiff) -ERR NORMAL_CLEARING 2012-11-08 21:21:08.409369 [DEBUG] switch_ivr_originate.c:2005 Parsing global variables 2012-11-08 21:21:08.409369 [NOTICE] switch_channel.c:951 New Channel loopback/500-a [c2807b1f-acac-4e17-9271-6cf5c61000f2] 2012-11-08 21:21:08.409369 [DEBUG] mod_loopback.c:154 loopback/500-a setup codec L16/8000/20 2012-11-08 21:21:08.409369 [NOTICE] switch_channel.c:949 Rename Channel loopback/500-a->loopback/500-a [c2807b1f-acac-4e17-9271-6cf5c61000f2] 2012-11-08 21:21:08.409369 [DEBUG] mod_loopback.c:1069 (loopback/500-a) State Change CS_NEW -> CS_INIT 2012-11-08 21:21:08.409369 [DEBUG] switch_core_session.c:1210 Send signal loopback/500-a [BREAK] 2012-11-08 21:21:08.409369 [DEBUG] mod_loopback.c:501 loopback/500-a CHANNEL KILL 2012-11-08 21:21:08.409369 [DEBUG] switch_core_state_machine.c:398 (loopback/500-a) Running State Change CS_INIT 2012-11-08 21:21:08.409369 [DEBUG] switch_core_state_machine.c:437 (loopback/500-a) State INIT 2012-11-08 21:21:08.409369 [NOTICE] switch_channel.c:951 New Channel loopback/500-b [d3de53aa-7a3e-483b-bd3f-434eba87815b] 2012-11-08 21:21:08.409369 [DEBUG] mod_loopback.c:154 loopback/500-b setup codec L16/8000/20 2012-11-08 21:21:08.409369 [DEBUG] mod_loopback.c:268 (loopback/500-b) State Change CS_NEW -> CS_INIT 2012-11-08 21:21:08.409369 [DEBUG] switch_core_session.c:1210 Send signal loopback/500-b [BREAK] 2012-11-08 21:21:08.409369 [DEBUG] mod_loopback.c:501 loopback/500-b CHANNEL KILL 2012-11-08 21:21:08.409369 [DEBUG] mod_loopback.c:324 (loopback/500-a) State Change CS_INIT -> CS_ROUTING 2012-11-08 21:21:08.409369 [DEBUG] switch_core_session.c:1210 Send signal loopback/500-a [BREAK] 2012-11-08 21:21:08.409369 [DEBUG] mod_loopback.c:501 loopback/500-a CHANNEL KILL 2012-11-08 21:21:08.409369 [DEBUG] switch_core_state_machine.c:437 (loopback/500-a) State INIT going to sleep 2012-11-08 21:21:08.409369 [DEBUG] switch_core_state_machine.c:398 (loopback/500-a) Running State Change CS_ROUTING 2012-11-08 21:21:08.409369 [DEBUG] switch_channel.c:1964 (loopback/500-a) Callstate Change DOWN -> RINGING 2012-11-08 21:21:08.409369 [DEBUG] switch_core_state_machine.c:446 (loopback/500-a) State ROUTING 2012-11-08 21:21:08.409369 [DEBUG] mod_loopback.c:356 loopback/500-a CHANNEL ROUTING 2012-11-08 21:21:08.409369 [DEBUG] switch_ivr_originate.c:67 (loopback/500-a) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2012-11-08 21:21:08.409369 [DEBUG] switch_core_session.c:1210 Send signal loopback/500-a [BREAK] 2012-11-08 21:21:08.409369 [DEBUG] mod_loopback.c:501 loopback/500-a CHANNEL KILL 2012-11-08 21:21:08.409369 [DEBUG] switch_core_state_machine.c:446 (loopback/500-a) State ROUTING going to sleep 2012-11-08 21:21:08.409369 [DEBUG] switch_core_state_machine.c:398 (loopback/500-a) Running State Change CS_CONSUME_MEDIA 2012-11-08 21:21:08.409369 [DEBUG] switch_core_state_machine.c:465 (loopback/500-a) State CONSUME_MEDIA 2012-11-08 21:21:08.409369 [DEBUG] mod_loopback.c:561 CHANNEL CONSUME_MEDIA 2012-11-08 21:21:08.409369 [DEBUG] switch_core_state_machine.c:465 (loopback/500-a) State CONSUME_MEDIA going to sleep 2012-11-08 21:21:08.409369 [DEBUG] switch_core_state_machine.c:398 (loopback/500-b) Running State Change CS_INIT 2012-11-08 21:21:08.409369 [DEBUG] switch_core_state_machine.c:437 (loopback/500-b) State INIT 2012-11-08 21:21:08.409369 [DEBUG] mod_loopback.c:324 (loopback/500-b) State Change CS_INIT -> CS_ROUTING 2012-11-08 21:21:08.409369 [DEBUG] switch_core_session.c:1210 Send signal loopback/500-b [BREAK] 2012-11-08 21:21:08.409369 [DEBUG] mod_loopback.c:501 loopback/500-b CHANNEL KILL 2012-11-08 21:21:08.409369 [DEBUG] switch_core_state_machine.c:437 (loopback/500-b) State INIT going to sleep 2012-11-08 21:21:08.409369 [DEBUG] switch_core_state_machine.c:398 (loopback/500-b) Running State Change CS_ROUTING 2012-11-08 21:21:08.409369 [DEBUG] switch_channel.c:1964 (loopback/500-b) Callstate Change DOWN -> RINGING 2012-11-08 21:21:08.409369 [DEBUG] switch_core_state_machine.c:446 (loopback/500-b) State ROUTING 2012-11-08 21:21:08.409369 [DEBUG] mod_loopback.c:356 loopback/500-b CHANNEL ROUTING 2012-11-08 21:21:08.409369 [DEBUG] switch_core_state_machine.c:117 loopback/500-b Standard ROUTING 2012-11-08 21:21:08.409369 [INFO] mod_dialplan_xml.c:485 Processing <0000000000>->500 in context default Dialplan: loopback/500-b parsing [default->unloop] continue=false Dialplan: loopback/500-b Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: loopback/500-b Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: loopback/500-b parsing [default->tod_example] continue=true Dialplan: loopback/500-b Date/TimeMatch (FAIL) [tod_example] break=on-false Dialplan: loopback/500-b parsing [default->holiday_example] continue=true Dialplan: loopback/500-b Date/TimeMatch (FAIL) [holiday_example] break=on-false Dialplan: loopback/500-b parsing [default->global-intercept] continue=false Dialplan: loopback/500-b Regex (FAIL) [global-intercept] destination_number(500) =~ /^886$/ break=on-false Dialplan: loopback/500-b parsing [default->group-intercept] continue=false Dialplan: loopback/500-b Regex (FAIL) [group-intercept] destination_number(500) =~ /^\*8$/ break=on-false Dialplan: loopback/500-b parsing [default->intercept-ext] continue=false Dialplan: loopback/500-b Regex (FAIL) [intercept-ext] destination_number(500) =~ /^\*\*(\d+)$/ break=on-false Dialplan: loopback/500-b parsing [default->redial] continue=false Dialplan: loopback/500-b Regex (FAIL) [redial] destination_number(500) =~ /^(redial|870)$/ break=on-false Dialplan: loopback/500-b parsing [default->global] continue=true Dialplan: loopback/500-b Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never Dialplan: loopback/500-b Regex (FAIL) [global] ${sip_has_crypto}() =~ /^(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)$/ break=never Dialplan: loopback/500-b Absolute Condition [global] Dialplan: loopback/500-b Action hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid}) Dialplan: loopback/500-b Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number}) Dialplan: loopback/500-b Action hash(insert/${domain_name}-last_dial/global/${uuid}) Dialplan: loopback/500-b Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) Dialplan: loopback/500-b parsing [default->snom-demo-2] continue=false Dialplan: loopback/500-b Regex (FAIL) [snom-demo-2] destination_number(500) =~ /^9001$/ break=on-false Dialplan: loopback/500-b parsing [default->snom-demo-1] continue=false Dialplan: loopback/500-b Regex (FAIL) [snom-demo-1] destination_number(500) =~ /^9000$/ break=on-false Dialplan: loopback/500-b parsing [default->eavesdrop] continue=false Dialplan: loopback/500-b Regex (FAIL) [eavesdrop] destination_number(500) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false Dialplan: loopback/500-b parsing [default->eavesdrop] continue=false Dialplan: loopback/500-b Regex (FAIL) [eavesdrop] destination_number(500) =~ /^779$/ break=on-false Dialplan: loopback/500-b parsing [default->call_return] continue=false Dialplan: loopback/500-b Regex (FAIL) [call_return] destination_number(500) =~ /^\*69$|^869$|^lcr$/ break=on-false Dialplan: loopback/500-b parsing [default->del-group] continue=false Dialplan: loopback/500-b Regex (FAIL) [del-group] destination_number(500) =~ /^80(\d{2})$/ break=on-false Dialplan: loopback/500-b parsing [default->add-group] continue=false Dialplan: loopback/500-b Regex (FAIL) [add-group] destination_number(500) =~ /^81(\d{2})$/ break=on-false Dialplan: loopback/500-b parsing [default->call-group-simo] continue=false Dialplan: loopback/500-b Regex (FAIL) [call-group-simo] destination_number(500) =~ /^82(\d{2})$/ break=on-false Dialplan: loopback/500-b parsing [default->call-group-order] continue=false Dialplan: loopback/500-b Regex (FAIL) [call-group-order] destination_number(500) =~ /^83(\d{2})$/ break=on-false Dialplan: loopback/500-b parsing [default->extension-intercom] continue=false Dialplan: loopback/500-b Regex (FAIL) [extension-intercom] destination_number(500) =~ /^8(10[01][0-9])$/ break=on-false Dialplan: loopback/500-b parsing [default->Local_Extension] continue=false Dialplan: loopback/500-b Regex (FAIL) [Local_Extension] destination_number(500) =~ /^(10[01][0-9])$/ break=on-false Dialplan: loopback/500-b parsing [default->Local_Extension_Skinny] continue=false Dialplan: loopback/500-b Regex (FAIL) [Local_Extension_Skinny] destination_number(500) =~ /^(11[01][0-9])$/ break=on-false Dialplan: loopback/500-b parsing [default->group_dial_sales] continue=false Dialplan: loopback/500-b Regex (FAIL) [group_dial_sales] destination_number(500) =~ /^2000$/ break=on-false Dialplan: loopback/500-b parsing [default->group_dial_support] continue=false Dialplan: loopback/500-b Regex (FAIL) [group_dial_support] destination_number(500) =~ /^2001$/ break=on-false Dialplan: loopback/500-b parsing [default->group_dial_billing] continue=false Dialplan: loopback/500-b Regex (FAIL) [group_dial_billing] destination_number(500) =~ /^2002$/ break=on-false Dialplan: loopback/500-b parsing [default->operator] continue=false Dialplan: loopback/500-b Regex (FAIL) [operator] destination_number(500) =~ /^(operator|0)$/ break=on-false Dialplan: loopback/500-b parsing [default->vmain] continue=false Dialplan: loopback/500-b Regex (FAIL) [vmain] destination_number(500) =~ /^vmain$|^4000$|^\*98$/ break=on-false Dialplan: loopback/500-b parsing [default->sip_uri] continue=false Dialplan: loopback/500-b Regex (FAIL) [sip_uri] destination_number(500) =~ /^sip:(.*)$/ break=on-false Dialplan: loopback/500-b parsing [default->nb_conferences] continue=false Dialplan: loopback/500-b Regex (FAIL) [nb_conferences] destination_number(500) =~ /^(30\d{2})$/ break=on-false Dialplan: loopback/500-b parsing [default->wb_conferences] continue=false Dialplan: loopback/500-b Regex (FAIL) [wb_conferences] destination_number(500) =~ /^(31\d{2})$/ break=on-false Dialplan: loopback/500-b parsing [default->uwb_conferences] continue=false Dialplan: loopback/500-b Regex (FAIL) [uwb_conferences] destination_number(500) =~ /^(32\d{2})$/ break=on-false Dialplan: loopback/500-b parsing [default->cdquality_conferences] continue=false Dialplan: loopback/500-b Regex (FAIL) [cdquality_conferences] destination_number(500) =~ /^(33\d{2})$/ break=on-false Dialplan: loopback/500-b parsing [default->freeswitch_public_conf_via_sip] continue=false Dialplan: loopback/500-b Regex (FAIL) [freeswitch_public_conf_via_sip] destination_number(500) =~ /^9(888|8888|1616|3232)$/ break=on-false Dialplan: loopback/500-b parsing [default->mad_boss_intercom] continue=false Dialplan: loopback/500-b Regex (FAIL) [mad_boss_intercom] destination_number(500) =~ /^0911$/ break=on-false Dialplan: loopback/500-b parsing [default->mad_boss_intercom] continue=false Dialplan: loopback/500-b Regex (FAIL) [mad_boss_intercom] destination_number(500) =~ /^0912$/ break=on-false Dialplan: loopback/500-b parsing [default->mad_boss] continue=false Dialplan: loopback/500-b Regex (FAIL) [mad_boss] destination_number(500) =~ /^0913$/ break=on-false Dialplan: loopback/500-b parsing [default->ivr_demo] continue=false Dialplan: loopback/500-b Regex (FAIL) [ivr_demo] destination_number(500) =~ /^5000$/ break=on-false Dialplan: loopback/500-b parsing [default->dynamic_conference] continue=false Dialplan: loopback/500-b Regex (FAIL) [dynamic_conference] destination_number(500) =~ /^5001$/ break=on-false Dialplan: loopback/500-b parsing [default->rtp_multicast_page] continue=false Dialplan: loopback/500-b Regex (FAIL) [rtp_multicast_page] destination_number(500) =~ /^pagegroup$|^7243$/ break=on-false Dialplan: loopback/500-b parsing [default->park] continue=false Dialplan: loopback/500-b Regex (FAIL) [park] destination_number(500) =~ /^5900$/ break=on-false Dialplan: loopback/500-b parsing [default->unpark] continue=false Dialplan: loopback/500-b Regex (FAIL) [unpark] destination_number(500) =~ /^5901$/ break=on-false Dialplan: loopback/500-b parsing [default->valet_park] continue=false Dialplan: loopback/500-b Regex (FAIL) [valet_park] destination_number(500) =~ /^(6000)$/ break=on-false Dialplan: loopback/500-b parsing [default->valet_park] continue=false Dialplan: loopback/500-b Regex (FAIL) [valet_park] destination_number(500) =~ /^(60\d[1-9])$/ break=on-false Dialplan: loopback/500-b parsing [default->park] continue=false Dialplan: loopback/500-b Regex (FAIL) [park] source(mod_loopback) =~ /mod_sofia/ break=on-false Dialplan: loopback/500-b parsing [default->unpark] continue=false Dialplan: loopback/500-b Regex (FAIL) [unpark] source(mod_loopback) =~ /mod_sofia/ break=on-false Dialplan: loopback/500-b parsing [default->park] continue=false Dialplan: loopback/500-b Regex (FAIL) [park] source(mod_loopback) =~ /mod_sofia/ break=on-false Dialplan: loopback/500-b parsing [default->unpark] continue=false Dialplan: loopback/500-b Regex (FAIL) [unpark] source(mod_loopback) =~ /mod_sofia/ break=on-false Dialplan: loopback/500-b parsing [default->wait] continue=false Dialplan: loopback/500-b Regex (FAIL) [wait] destination_number(500) =~ /^wait$/ break=on-false Dialplan: loopback/500-b parsing [default->fax_receive] continue=false Dialplan: loopback/500-b Regex (FAIL) [fax_receive] destination_number(500) =~ /^9178$/ break=on-false Dialplan: loopback/500-b parsing [default->fax_transmit] continue=false Dialplan: loopback/500-b Regex (FAIL) [fax_transmit] destination_number(500) =~ /^9179$/ break=on-false Dialplan: loopback/500-b parsing [default->ringback_180] continue=false Dialplan: loopback/500-b Regex (FAIL) [ringback_180] destination_number(500) =~ /^9180$/ break=on-false Dialplan: loopback/500-b parsing [default->ringback_183_uk_ring] continue=false Dialplan: loopback/500-b Regex (FAIL) [ringback_183_uk_ring] destination_number(500) =~ /^9181$/ break=on-false Dialplan: loopback/500-b parsing [default->ringback_183_music_ring] continue=false Dialplan: loopback/500-b Regex (FAIL) [ringback_183_music_ring] destination_number(500) =~ /^9182$/ break=on-false Dialplan: loopback/500-b parsing [default->ringback_post_answer_uk_ring] continue=false Dialplan: loopback/500-b Regex (FAIL) [ringback_post_answer_uk_ring] destination_number(500) =~ /^9183$/ break=on-false Dialplan: loopback/500-b parsing [default->ringback_post_answer_music] continue=false Dialplan: loopback/500-b Regex (FAIL) [ringback_post_answer_music] destination_number(500) =~ /^9184$/ break=on-false Dialplan: loopback/500-b parsing [default->ClueCon] continue=false Dialplan: loopback/500-b Regex (FAIL) [ClueCon] destination_number(500) =~ /^9191$/ break=on-false Dialplan: loopback/500-b parsing [default->show_info] continue=false Dialplan: loopback/500-b Regex (FAIL) [show_info] destination_number(500) =~ /^9192$/ break=on-false Dialplan: loopback/500-b parsing [default->video_record] continue=false Dialplan: loopback/500-b Regex (FAIL) [video_record] destination_number(500) =~ /^9193$/ break=on-false Dialplan: loopback/500-b parsing [default->video_playback] continue=false Dialplan: loopback/500-b Regex (FAIL) [video_playback] destination_number(500) =~ /^9194$/ break=on-false Dialplan: loopback/500-b parsing [default->delay_echo] continue=false Dialplan: loopback/500-b Regex (FAIL) [delay_echo] destination_number(500) =~ /^9195$/ break=on-false Dialplan: loopback/500-b parsing [default->echo] continue=false Dialplan: loopback/500-b Regex (FAIL) [echo] destination_number(500) =~ /^9196$/ break=on-false Dialplan: loopback/500-b parsing [default->milliwatt] continue=false Dialplan: loopback/500-b Regex (FAIL) [milliwatt] destination_number(500) =~ /^9197$/ break=on-false Dialplan: loopback/500-b parsing [default->tone_stream] continue=false Dialplan: loopback/500-b Regex (FAIL) [tone_stream] destination_number(500) =~ /^9198$/ break=on-false Dialplan: loopback/500-b parsing [default->zrtp_enrollement] continue=false Dialplan: loopback/500-b Regex (FAIL) [zrtp_enrollement] destination_number(500) =~ /^9787$/ break=on-false Dialplan: loopback/500-b parsing [default->hold_music] continue=false Dialplan: loopback/500-b Regex (FAIL) [hold_music] destination_number(500) =~ /^9664$/ break=on-false Dialplan: loopback/500-b parsing [default->laugh break] continue=false Dialplan: loopback/500-b Regex (FAIL) [laugh break] destination_number(500) =~ /^9386$/ break=on-false Dialplan: loopback/500-b parsing [default->5555555] continue=false Dialplan: loopback/500-b Regex (FAIL) [5555555] destination_number(500) =~ /^(1000)$/ break=on-false Dialplan: loopback/500-b parsing [default->fax] continue=false Dialplan: loopback/500-b Absolute Condition [fax] Dialplan: loopback/500-b Action set(fax_enable_t38=true) Dialplan: loopback/500-b Action set(execute_on_answer=t38_gateway self) Dialplan: loopback/500-b Action set(proxy_media=true) Dialplan: loopback/500-b Action bridge(user/500(a)192.168.13.18) 2012-11-08 21:21:08.409369 [DEBUG] switch_core_state_machine.c:167 (loopback/500-b) State Change CS_ROUTING -> CS_EXECUTE 2012-11-08 21:21:08.409369 [DEBUG] switch_core_session.c:1210 Send signal loopback/500-b [BREAK] 2012-11-08 21:21:08.409369 [DEBUG] mod_loopback.c:501 loopback/500-b CHANNEL KILL 2012-11-08 21:21:08.409369 [DEBUG] switch_core_state_machine.c:446 (loopback/500-b) State ROUTING going to sleep 2012-11-08 21:21:08.409369 [DEBUG] switch_core_state_machine.c:398 (loopback/500-b) Running State Change CS_EXECUTE 2012-11-08 21:21:08.409369 [DEBUG] switch_core_state_machine.c:453 (loopback/500-b) State EXECUTE 2012-11-08 21:21:08.409369 [DEBUG] mod_loopback.c:395 loopback/500-b CHANNEL EXECUTE 2012-11-08 21:21:08.409369 [DEBUG] switch_core_state_machine.c:209 loopback/500-b Standard EXECUTE EXECUTE loopback/500-b hash(insert/192.168.13.18-spymap/0000000000/d3de53aa-7a3e-483b-bd3f-434eba87815b) EXECUTE loopback/500-b hash(insert/192.168.13.18-last_dial/0000000000/500) EXECUTE loopback/500-b hash(insert/192.168.13.18-last_dial/global/d3de53aa-7a3e-483b-bd3f-434eba87815b) EXECUTE loopback/500-b export(RFC2822_DATE=Thu, 08 Nov 2012 21:21:08 +0400) 2012-11-08 21:21:08.409369 [DEBUG] switch_channel.c:1118 EXPORT (export_vars) [RFC2822_DATE]=[Thu, 08 Nov 2012 21:21:08 +0400] EXECUTE loopback/500-b set(fax_enable_t38=true) 2012-11-08 21:21:08.409369 [DEBUG] mod_dptools.c:1319 loopback/500-b SET [fax_enable_t38]=[true] EXECUTE loopback/500-b set(execute_on_answer=t38_gateway self) 2012-11-08 21:21:08.409369 [DEBUG] mod_dptools.c:1319 loopback/500-b SET [execute_on_answer]=[t38_gateway self] EXECUTE loopback/500-b set(proxy_media=true) 2012-11-08 21:21:08.409369 [DEBUG] mod_dptools.c:1319 loopback/500-b SET [proxy_media]=[true] EXECUTE loopback/500-b bridge(user/500(a)192.168.13.18) 2012-11-08 21:21:08.409369 [DEBUG] switch_channel.c:1072 loopback/500-b EXPORTING[export_vars] [RFC2822_DATE]=[Thu, 08 Nov 2012 21:21:08 +0400] to event 2012-11-08 21:21:08.409369 [DEBUG] switch_ivr_originate.c:2005 Parsing global variables 2012-11-08 21:21:08.409369 [DEBUG] switch_channel.c:1072 loopback/500-b EXPORTING[export_vars] [RFC2822_DATE]=[Thu, 08 Nov 2012 21:21:08 +0400] to event 2012-11-08 21:21:08.409369 [DEBUG] switch_ivr_originate.c:2005 Parsing global variables 2012-11-08 21:21:08.409369 [DEBUG] switch_event.c:1569 Parsing variable [sip_invite_domain]=[192.168.13.18] 2012-11-08 21:21:08.409369 [DEBUG] switch_event.c:1569 Parsing variable [presence_id]=[500(a)192.168.13.18] 2012-11-08 21:21:08.409369 [NOTICE] switch_channel.c:951 New Channel sofia/internal/sip:500@192.168.13.233:5060 [f617d5ed-1e77-4a22-85a1-d0db3da0fc4f] 2012-11-08 21:21:08.409369 [DEBUG] mod_sofia.c:4879 (sofia/internal/sip:500@192.168.13.233:5060) State Change CS_NEW -> CS_INIT 2012-11-08 21:21:08.409369 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/sip:500@192.168.13.233:5060 [BREAK] 2012-11-08 21:21:08.429387 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/sip:500@192.168.13.233:5060) Running State Change CS_INIT 2012-11-08 21:21:08.429387 [DEBUG] switch_core_state_machine.c:437 (sofia/internal/sip:500@192.168.13.233:5060) State INIT 2012-11-08 21:21:08.429387 [DEBUG] mod_sofia.c:86 sofia/internal/sip:500@192.168.13.233:5060 SOFIA INIT 2012-11-08 21:21:08.429387 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/sip:500@192.168.13.233:5060 [BREAK] 2012-11-08 21:21:08.429387 [DEBUG] mod_sofia.c:126 (sofia/internal/sip:500@192.168.13.233:5060) State Change CS_INIT -> CS_ROUTING 2012-11-08 21:21:08.429387 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/sip:500@192.168.13.233:5060 [BREAK] 2012-11-08 21:21:08.429387 [DEBUG] switch_core_state_machine.c:437 (sofia/internal/sip:500@192.168.13.233:5060) State INIT going to sleep 2012-11-08 21:21:08.429387 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/sip:500@192.168.13.233:5060) Running State Change CS_ROUTING 2012-11-08 21:21:08.429387 [DEBUG] switch_channel.c:1964 (sofia/internal/sip:500@192.168.13.233:5060) Callstate Change DOWN -> RINGING 2012-11-08 21:21:08.429387 [DEBUG] switch_core_state_machine.c:446 (sofia/internal/sip:500@192.168.13.233:5060) State ROUTING 2012-11-08 21:21:08.429387 [DEBUG] mod_sofia.c:149 sofia/internal/sip:500@192.168.13.233:5060 SOFIA ROUTING 2012-11-08 21:21:08.429387 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/sip:500@192.168.13.233:5060) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2012-11-08 21:21:08.429387 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/sip:500@192.168.13.233:5060 [BREAK] 2012-11-08 21:21:08.429387 [DEBUG] switch_core_state_machine.c:446 (sofia/internal/sip:500@192.168.13.233:5060) State ROUTING going to sleep 2012-11-08 21:21:08.429387 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/sip:500@192.168.13.233:5060) Running State Change CS_CONSUME_MEDIA 2012-11-08 21:21:08.429387 [DEBUG] switch_core_state_machine.c:465 (sofia/internal/sip:500@192.168.13.233:5060) State CONSUME_MEDIA 2012-11-08 21:21:08.429387 [DEBUG] switch_core_state_machine.c:465 (sofia/internal/sip:500@192.168.13.233:5060) State CONSUME_MEDIA going to sleep 2012-11-08 21:21:08.429387 [DEBUG] sofia.c:6282 Channel sofia/internal/sip:500@192.168.13.233:5060 entering state [calling][0] 2012-11-08 21:21:29.609239 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/sip:500@192.168.13.233:5060 [BREAK] 2012-11-08 21:21:29.609239 [DEBUG] switch_channel.c:2950 (sofia/internal/sip:500@192.168.13.233:5060) Callstate Change RINGING -> HANGUP 2012-11-08 21:21:29.609239 [NOTICE] sofia.c:711 Hangup sofia/internal/sip:500@192.168.13.233:5060 [CS_CONSUME_MEDIA] [NORMAL_CLEARING] 2012-11-08 21:21:29.609239 [DEBUG] switch_channel.c:2973 Send signal sofia/internal/sip:500@192.168.13.233:5060 [KILL] 2012-11-08 21:21:29.609239 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/sip:500@192.168.13.233:5060 [BREAK] 2012-11-08 21:21:29.609239 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/sip:500@192.168.13.233:5060) Running State Change CS_HANGUP 2012-11-08 21:21:29.609239 [DEBUG] switch_core_state_machine.c:638 (sofia/internal/sip:500@192.168.13.233:5060) State HANGUP 2012-11-08 21:21:29.609239 [DEBUG] mod_sofia.c:483 Channel sofia/internal/sip:500@192.168.13.233:5060 hanging up, cause: NORMAL_CLEARING 2012-11-08 21:21:29.609239 [DEBUG] switch_core_state_machine.c:48 sofia/internal/sip:500@192.168.13.233:5060 Standard HANGUP, cause: NORMAL_CLEARING 2012-11-08 21:21:29.609239 [DEBUG] switch_core_state_machine.c:638 (sofia/internal/sip:500@192.168.13.233:5060) State HANGUP going to sleep 2012-11-08 21:21:29.609239 [DEBUG] switch_core_state_machine.c:429 (sofia/internal/sip:500@192.168.13.233:5060) State Change CS_HANGUP -> CS_REPORTING 2012-11-08 21:21:29.609239 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/sip:500@192.168.13.233:5060 [BREAK] 2012-11-08 21:21:29.609239 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/sip:500@192.168.13.233:5060) Running State Change CS_REPORTING 2012-11-08 21:21:29.609239 [DEBUG] switch_core_state_machine.c:703 (sofia/internal/sip:500@192.168.13.233:5060) State REPORTING 2012-11-08 21:21:29.609239 [DEBUG] switch_core_state_machine.c:92 sofia/internal/sip:500@192.168.13.233:5060 Standard REPORTING, cause: NORMAL_CLEARING 2012-11-08 21:21:29.609239 [DEBUG] switch_core_state_machine.c:703 (sofia/internal/sip:500@192.168.13.233:5060) State REPORTING going to sleep 2012-11-08 21:21:29.609239 [DEBUG] switch_core_state_machine.c:423 (sofia/internal/sip:500@192.168.13.233:5060) State Change CS_REPORTING -> CS_DESTROY 2012-11-08 21:21:29.609239 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/sip:500@192.168.13.233:5060 [BREAK] 2012-11-08 21:21:29.609239 [DEBUG] switch_core_session.c:1415 Session 35 (sofia/internal/sip:500@192.168.13.233:5060) Locked, Waiting on external entities 2012-11-08 21:21:29.629589 [DEBUG] switch_ivr_originate.c:3508 Originate Resulted in Error Cause: 16 [NORMAL_CLEARING] 2012-11-08 21:21:29.629589 [NOTICE] switch_ivr_originate.c:2591 Cannot create outgoing channel of type [user] cause: [NORMAL_CLEARING] 2012-11-08 21:21:29.629589 [NOTICE] switch_core_session.c:1433 Session 35 (sofia/internal/sip:500@192.168.13.233:5060) Ended 2012-11-08 21:21:29.629589 [NOTICE] switch_core_session.c:1437 Close Channel sofia/internal/sip:500@192.168.13.233:5060 [CS_DESTROY] 2012-11-08 21:21:29.629589 [DEBUG] switch_ivr_originate.c:3508 Originate Resulted in Error Cause: 16 [NORMAL_CLEARING] 2012-11-08 21:21:29.629589 [INFO] mod_dptools.c:3027 Originate Failed. Cause: NORMAL_CLEARING 2012-11-08 21:21:29.629589 [DEBUG] switch_channel.c:2950 (loopback/500-b) Callstate Change RINGING -> HANGUP 2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:527 (sofia/internal/sip:500@192.168.13.233:5060) Callstate Change HANGUP -> DOWN 2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:530 (sofia/internal/sip:500@192.168.13.233:5060) Running State Change CS_DESTROY 2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:540 (sofia/internal/sip:500@192.168.13.233:5060) State DESTROY 2012-11-08 21:21:29.629589 [DEBUG] mod_sofia.c:376 sofia/internal/sip:500@192.168.13.233:5060 SOFIA DESTROY 2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:99 sofia/internal/sip:500@192.168.13.233:5060 Standard DESTROY 2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:540 (sofia/internal/sip:500@192.168.13.233:5060) State DESTROY going to sleep 2012-11-08 21:21:29.629589 [NOTICE] mod_dptools.c:3147 Hangup loopback/500-b [CS_EXECUTE] [NORMAL_CLEARING] 2012-11-08 21:21:29.629589 [DEBUG] switch_channel.c:2973 Send signal loopback/500-b [KILL] 2012-11-08 21:21:29.629589 [DEBUG] mod_loopback.c:501 loopback/500-b CHANNEL KILL 2012-11-08 21:21:29.629589 [DEBUG] switch_core_session.c:1210 Send signal loopback/500-b [BREAK] 2012-11-08 21:21:29.629589 [DEBUG] mod_loopback.c:501 loopback/500-b CHANNEL KILL 2012-11-08 21:21:29.629589 [DEBUG] switch_core_session.c:2553 loopback/500-b skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:453 (loopback/500-b) State EXECUTE going to sleep 2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:398 (loopback/500-b) Running State Change CS_HANGUP 2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:638 (loopback/500-b) State HANGUP 2012-11-08 21:21:29.629589 [DEBUG] mod_loopback.c:453 loopback/500-b CHANNEL HANGUP 2012-11-08 21:21:29.629589 [DEBUG] switch_channel.c:2950 (loopback/500-a) Callstate Change RINGING -> HANGUP 2012-11-08 21:21:29.629589 [NOTICE] mod_loopback.c:464 Hangup loopback/500-a [CS_CONSUME_MEDIA] [NORMAL_CLEARING] 2012-11-08 21:21:29.629589 [DEBUG] switch_channel.c:2973 Send signal loopback/500-a [KILL] 2012-11-08 21:21:29.629589 [DEBUG] mod_loopback.c:501 loopback/500-a CHANNEL KILL 2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:398 (loopback/500-a) Running State Change CS_HANGUP 2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:638 (loopback/500-a) State HANGUP 2012-11-08 21:21:29.629589 [DEBUG] mod_loopback.c:453 loopback/500-a CHANNEL HANGUP 2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:48 loopback/500-a Standard HANGUP, cause: NORMAL_CLEARING 2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:638 (loopback/500-a) State HANGUP going to sleep 2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:429 (loopback/500-a) State Change CS_HANGUP -> CS_REPORTING 2012-11-08 21:21:29.629589 [DEBUG] switch_core_session.c:1210 Send signal loopback/500-a [BREAK] 2012-11-08 21:21:29.629589 [DEBUG] mod_loopback.c:501 loopback/500-a CHANNEL KILL 2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:398 (loopback/500-a) Running State Change CS_REPORTING 2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:703 (loopback/500-a) State REPORTING 2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:92 loopback/500-a Standard REPORTING, cause: NORMAL_CLEARING 2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:703 (loopback/500-a) State REPORTING going to sleep 2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:423 (loopback/500-a) State Change CS_REPORTING -> CS_DESTROY 2012-11-08 21:21:29.629589 [DEBUG] switch_core_session.c:1210 Send signal loopback/500-a [BREAK] 2012-11-08 21:21:29.629589 [DEBUG] mod_loopback.c:501 loopback/500-a CHANNEL KILL 2012-11-08 21:21:29.629589 [DEBUG] switch_core_session.c:1415 Session 33 (loopback/500-a) Locked, Waiting on external entities 2012-11-08 21:21:29.629589 [DEBUG] switch_core_session.c:1210 Send signal loopback/500-a [BREAK] 2012-11-08 21:21:29.629589 [DEBUG] mod_loopback.c:501 loopback/500-a CHANNEL KILL 2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:48 loopback/500-b Standard HANGUP, cause: NORMAL_CLEARING 2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:638 (loopback/500-b) State HANGUP going to sleep 2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:429 (loopback/500-b) State Change CS_HANGUP -> CS_REPORTING 2012-11-08 21:21:29.629589 [DEBUG] switch_core_session.c:1210 Send signal loopback/500-b [BREAK] 2012-11-08 21:21:29.629589 [DEBUG] mod_loopback.c:501 loopback/500-b CHANNEL KILL 2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:398 (loopback/500-b) Running State Change CS_REPORTING 2012-11-08 21:21:29.629589 [DEBUG] switch_ivr_originate.c:3508 Originate Resulted in Error Cause: 16 [NORMAL_CLEARING] 2012-11-08 21:21:29.629589 [NOTICE] switch_core_session.c:1433 Session 33 (loopback/500-a) Ended 2012-11-08 21:21:29.629589 [NOTICE] switch_core_session.c:1437 Close Channel loopback/500-a [CS_DESTROY] 2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:527 (loopback/500-a) Callstate Change HANGUP -> DOWN 2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:530 (loopback/500-a) Running State Change CS_DESTROY 2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:540 (loopback/500-a) State DESTROY 2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:99 loopback/500-a Standard DESTROY 2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:540 (loopback/500-a) State DESTROY going to sleep 2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:703 (loopback/500-b) State REPORTING 2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:92 loopback/500-b Standard REPORTING, cause: NORMAL_CLEARING 2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:703 (loopback/500-b) State REPORTING going to sleep 2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:423 (loopback/500-b) State Change CS_REPORTING -> CS_DESTROY 2012-11-08 21:21:29.629589 [DEBUG] switch_core_session.c:1210 Send signal loopback/500-b [BREAK] 2012-11-08 21:21:29.629589 [DEBUG] mod_loopback.c:501 loopback/500-b CHANNEL KILL 2012-11-08 21:21:29.629589 [DEBUG] switch_core_session.c:1415 Session 34 (loopback/500-b) Locked, Waiting on external entities 2012-11-08 21:21:29.629589 [NOTICE] switch_core_session.c:1433 Session 34 (loopback/500-b) Ended 2012-11-08 21:21:29.629589 [NOTICE] switch_core_session.c:1437 Close Channel loopback/500-b [CS_DESTROY] 2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:527 (loopback/500-b) Callstate Change HANGUP -> DOWN 2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:530 (loopback/500-b) Running State Change CS_DESTROY 2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:540 (loopback/500-b) State DESTROY 2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:99 loopback/500-b Standard DESTROY 2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:540 (loopback/500-b) State DESTROY going to sleep so I'm trying to send a fax to the fax 501 -> 500 log: 2012-11-08 21:18:21.109351 [NOTICE] switch_channel.c:951 New Channel sofia/internal/501(a)192.168.13.18 [ce35cc96-6ce5-4cf7-a9f0-71f7d31e454d] 2012-11-08 21:18:21.109351 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/501(a)192.168.13.18 [BREAK] 2012-11-08 21:18:21.129757 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/501(a)192.168.13.18) Running State Change CS_NEW 2012-11-08 21:18:21.129757 [DEBUG] switch_core_state_machine.c:416 (sofia/internal/501(a)192.168.13.18) State NEW 2012-11-08 21:18:21.129757 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/501(a)192.168.13.18 [BREAK] 2012-11-08 21:18:21.149399 [DEBUG] sofia.c:8412 IP 192.168.13.71 Rejected by acl "domains". Falling back to Digest auth. 2012-11-08 21:18:21.149399 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/501(a)192.168.13.18 [BREAK] 2012-11-08 21:18:21.149399 [DEBUG] sofia.c:1728 detaching session ce35cc96-6ce5-4cf7-a9f0-71f7d31e454d 2012-11-08 21:18:21.149399 [DEBUG] sofia.c:1820 Re-attaching to session ce35cc96-6ce5-4cf7-a9f0-71f7d31e454d 2012-11-08 21:18:21.149399 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/501(a)192.168.13.18 [BREAK] 2012-11-08 21:18:21.149399 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/501(a)192.168.13.18 [BREAK] 2012-11-08 21:18:21.169346 [DEBUG] sofia.c:8412 IP 192.168.13.71 Rejected by acl "domains". Falling back to Digest auth. 2012-11-08 21:18:21.169346 [DEBUG] sofia.c:6282 Channel sofia/internal/501(a)192.168.13.18 entering state [received][100] 2012-11-08 21:18:21.169346 [DEBUG] sofia.c:6293 Remote SDP: v=0 o=- 1352395099 1 IN IP4 192.168.13.71 s=VFT38M/v.25.08.2012 c=IN IP4 192.168.13.71 t=0 0 m=audio 5018 RTP/AVP 0 8 101 a=rtpmap:0 PCMU/8000/1 a=rtpmap:8 PCMA/8000/1 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16,32,36 a=maxptime:240 2012-11-08 21:18:21.169346 [DEBUG] sofia.c:6506 (sofia/internal/501(a)192.168.13.18) State Change CS_NEW -> CS_INIT 2012-11-08 21:18:21.169346 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/501(a)192.168.13.18 [BREAK] 2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/501(a)192.168.13.18) Running State Change CS_INIT 2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:437 (sofia/internal/501(a)192.168.13.18) State INIT 2012-11-08 21:18:21.169346 [DEBUG] mod_sofia.c:86 sofia/internal/501(a)192.168.13.18 SOFIA INIT 2012-11-08 21:18:21.169346 [DEBUG] mod_sofia.c:126 (sofia/internal/501(a)192.168.13.18) State Change CS_INIT -> CS_ROUTING 2012-11-08 21:18:21.169346 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/501(a)192.168.13.18 [BREAK] 2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:437 (sofia/internal/501(a)192.168.13.18) State INIT going to sleep 2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/501(a)192.168.13.18) Running State Change CS_ROUTING 2012-11-08 21:18:21.169346 [DEBUG] switch_channel.c:1964 (sofia/internal/501(a)192.168.13.18) Callstate Change DOWN -> RINGING 2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:446 (sofia/internal/501(a)192.168.13.18) State ROUTING 2012-11-08 21:18:21.169346 [DEBUG] mod_sofia.c:149 sofia/internal/501(a)192.168.13.18 SOFIA ROUTING 2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:117 sofia/internal/501(a)192.168.13.18 Standard ROUTING 2012-11-08 21:18:21.169346 [INFO] mod_dialplan_xml.c:485 Processing 501 <501>->500 in context default Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->unloop] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->tod_example] continue=true Dialplan: sofia/internal/501(a)192.168.13.18 Date/TimeMatch (FAIL) [tod_example] break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->holiday_example] continue=true Dialplan: sofia/internal/501(a)192.168.13.18 Date/TimeMatch (FAIL) [holiday_example] break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->global-intercept] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [global-intercept] destination_number(500) =~ /^886$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->group-intercept] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [group-intercept] destination_number(500) =~ /^\*8$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->intercept-ext] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [intercept-ext] destination_number(500) =~ /^\*\*(\d+)$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->redial] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [redial] destination_number(500) =~ /^(redial|870)$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->global] continue=true Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [global] ${sip_has_crypto}() =~ /^(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)$/ break=never Dialplan: sofia/internal/501(a)192.168.13.18 Absolute Condition [global] Dialplan: sofia/internal/501(a)192.168.13.18 Action hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid}) Dialplan: sofia/internal/501(a)192.168.13.18 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number}) Dialplan: sofia/internal/501(a)192.168.13.18 Action hash(insert/${domain_name}-last_dial/global/${uuid}) Dialplan: sofia/internal/501(a)192.168.13.18 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->snom-demo-2] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [snom-demo-2] destination_number(500) =~ /^9001$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->snom-demo-1] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [snom-demo-1] destination_number(500) =~ /^9000$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->eavesdrop] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [eavesdrop] destination_number(500) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->eavesdrop] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [eavesdrop] destination_number(500) =~ /^779$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->call_return] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [call_return] destination_number(500) =~ /^\*69$|^869$|^lcr$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->del-group] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [del-group] destination_number(500) =~ /^80(\d{2})$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->add-group] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [add-group] destination_number(500) =~ /^81(\d{2})$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->call-group-simo] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [call-group-simo] destination_number(500) =~ /^82(\d{2})$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->call-group-order] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [call-group-order] destination_number(500) =~ /^83(\d{2})$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->extension-intercom] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [extension-intercom] destination_number(500) =~ /^8(10[01][0-9])$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->Local_Extension] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [Local_Extension] destination_number(500) =~ /^(10[01][0-9])$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->Local_Extension_Skinny] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [Local_Extension_Skinny] destination_number(500) =~ /^(11[01][0-9])$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->group_dial_sales] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [group_dial_sales] destination_number(500) =~ /^2000$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->group_dial_support] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [group_dial_support] destination_number(500) =~ /^2001$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->group_dial_billing] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [group_dial_billing] destination_number(500) =~ /^2002$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->operator] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [operator] destination_number(500) =~ /^(operator|0)$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->vmain] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [vmain] destination_number(500) =~ /^vmain$|^4000$|^\*98$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->sip_uri] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [sip_uri] destination_number(500) =~ /^sip:(.*)$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->nb_conferences] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [nb_conferences] destination_number(500) =~ /^(30\d{2})$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->wb_conferences] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [wb_conferences] destination_number(500) =~ /^(31\d{2})$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->uwb_conferences] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [uwb_conferences] destination_number(500) =~ /^(32\d{2})$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->cdquality_conferences] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [cdquality_conferences] destination_number(500) =~ /^(33\d{2})$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->freeswitch_public_conf_via_sip] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [freeswitch_public_conf_via_sip] destination_number(500) =~ /^9(888|8888|1616|3232)$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->mad_boss_intercom] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [mad_boss_intercom] destination_number(500) =~ /^0911$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->mad_boss_intercom] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [mad_boss_intercom] destination_number(500) =~ /^0912$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->mad_boss] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [mad_boss] destination_number(500) =~ /^0913$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->ivr_demo] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [ivr_demo] destination_number(500) =~ /^5000$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->dynamic_conference] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [dynamic_conference] destination_number(500) =~ /^5001$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->rtp_multicast_page] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [rtp_multicast_page] destination_number(500) =~ /^pagegroup$|^7243$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->park] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [park] destination_number(500) =~ /^5900$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->unpark] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [unpark] destination_number(500) =~ /^5901$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->valet_park] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [valet_park] destination_number(500) =~ /^(6000)$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->valet_park] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [valet_park] destination_number(500) =~ /^(60\d[1-9])$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->park] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (PASS) [park] source(mod_sofia) =~ /mod_sofia/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [park] destination_number(500) =~ /park\+(\d+)/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->unpark] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (PASS) [unpark] source(mod_sofia) =~ /mod_sofia/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [unpark] destination_number(500) =~ /^parking$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->park] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (PASS) [park] source(mod_sofia) =~ /mod_sofia/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [park] destination_number(500) =~ /callpark/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->unpark] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (PASS) [unpark] source(mod_sofia) =~ /mod_sofia/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [unpark] destination_number(500) =~ /pickup/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->wait] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [wait] destination_number(500) =~ /^wait$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->fax_receive] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [fax_receive] destination_number(500) =~ /^9178$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->fax_transmit] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [fax_transmit] destination_number(500) =~ /^9179$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->ringback_180] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [ringback_180] destination_number(500) =~ /^9180$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->ringback_183_uk_ring] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [ringback_183_uk_ring] destination_number(500) =~ /^9181$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->ringback_183_music_ring] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [ringback_183_music_ring] destination_number(500) =~ /^9182$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->ringback_post_answer_uk_ring] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [ringback_post_answer_uk_ring] destination_number(500) =~ /^9183$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->ringback_post_answer_music] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [ringback_post_answer_music] destination_number(500) =~ /^9184$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->ClueCon] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [ClueCon] destination_number(500) =~ /^9191$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->show_info] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [show_info] destination_number(500) =~ /^9192$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->video_record] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [video_record] destination_number(500) =~ /^9193$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->video_playback] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [video_playback] destination_number(500) =~ /^9194$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->delay_echo] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [delay_echo] destination_number(500) =~ /^9195$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->echo] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [echo] destination_number(500) =~ /^9196$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->milliwatt] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [milliwatt] destination_number(500) =~ /^9197$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->tone_stream] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [tone_stream] destination_number(500) =~ /^9198$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->zrtp_enrollement] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [zrtp_enrollement] destination_number(500) =~ /^9787$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->hold_music] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [hold_music] destination_number(500) =~ /^9664$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->laugh break] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [laugh break] destination_number(500) =~ /^9386$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->5555555] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Regex (FAIL) [5555555] destination_number(500) =~ /^(1000)$/ break=on-false Dialplan: sofia/internal/501(a)192.168.13.18 parsing [default->fax] continue=false Dialplan: sofia/internal/501(a)192.168.13.18 Absolute Condition [fax] Dialplan: sofia/internal/501(a)192.168.13.18 Action set(fax_enable_t38=true) Dialplan: sofia/internal/501(a)192.168.13.18 Action set(execute_on_answer=t38_gateway self) Dialplan: sofia/internal/501(a)192.168.13.18 Action set(proxy_media=true) Dialplan: sofia/internal/501(a)192.168.13.18 Action bridge(user/500(a)192.168.13.18) 2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:167 (sofia/internal/501(a)192.168.13.18) State Change CS_ROUTING -> CS_EXECUTE 2012-11-08 21:18:21.169346 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/501(a)192.168.13.18 [BREAK] 2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:446 (sofia/internal/501(a)192.168.13.18) State ROUTING going to sleep 2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/501(a)192.168.13.18) Running State Change CS_EXECUTE 2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:453 (sofia/internal/501(a)192.168.13.18) State EXECUTE 2012-11-08 21:18:21.169346 [DEBUG] mod_sofia.c:242 sofia/internal/501(a)192.168.13.18 SOFIA EXECUTE 2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:209 sofia/internal/501(a)192.168.13.18 Standard EXECUTE EXECUTE sofia/internal/501(a)192.168.13.18 hash(insert/192.168.13.18-spymap/501/ce35cc96-6ce5-4cf7-a9f0-71f7d31e454d) EXECUTE sofia/internal/501(a)192.168.13.18 hash(insert/192.168.13.18-last_dial/501/500) EXECUTE sofia/internal/501(a)192.168.13.18 hash(insert/192.168.13.18-last_dial/global/ce35cc96-6ce5-4cf7-a9f0-71f7d31e454d) EXECUTE sofia/internal/501(a)192.168.13.18 export(RFC2822_DATE=Thu, 08 Nov 2012 21:18:21 +0400) 2012-11-08 21:18:21.169346 [DEBUG] switch_channel.c:1118 EXPORT (export_vars) [RFC2822_DATE]=[Thu, 08 Nov 2012 21:18:21 +0400] EXECUTE sofia/internal/501(a)192.168.13.18 set(fax_enable_t38=true) 2012-11-08 21:18:21.169346 [DEBUG] mod_dptools.c:1319 sofia/internal/501(a)192.168.13.18 SET [fax_enable_t38]=[true] EXECUTE sofia/internal/501(a)192.168.13.18 set(execute_on_answer=t38_gateway self) 2012-11-08 21:18:21.169346 [DEBUG] mod_dptools.c:1319 sofia/internal/501(a)192.168.13.18 SET [execute_on_answer]=[t38_gateway self] EXECUTE sofia/internal/501(a)192.168.13.18 set(proxy_media=true) 2012-11-08 21:18:21.169346 [DEBUG] mod_dptools.c:1319 sofia/internal/501(a)192.168.13.18 SET [proxy_media]=[true] EXECUTE sofia/internal/501(a)192.168.13.18 bridge(user/500(a)192.168.13.18) 2012-11-08 21:18:21.169346 [DEBUG] switch_channel.c:1072 sofia/internal/501(a)192.168.13.18 EXPORTING[export_vars] [RFC2822_DATE]=[Thu, 08 Nov 2012 21:18:21 +0400] to event 2012-11-08 21:18:21.169346 [DEBUG] switch_ivr_originate.c:2005 Parsing global variables 2012-11-08 21:18:21.169346 [DEBUG] switch_channel.c:1072 sofia/internal/501(a)192.168.13.18 EXPORTING[export_vars] [RFC2822_DATE]=[Thu, 08 Nov 2012 21:18:21 +0400] to event 2012-11-08 21:18:21.169346 [DEBUG] switch_ivr_originate.c:2005 Parsing global variables 2012-11-08 21:18:21.169346 [DEBUG] switch_event.c:1569 Parsing variable [sip_invite_domain]=[192.168.13.18] 2012-11-08 21:18:21.169346 [DEBUG] switch_event.c:1569 Parsing variable [presence_id]=[500(a)192.168.13.18] 2012-11-08 21:18:21.169346 [NOTICE] switch_channel.c:951 New Channel sofia/internal/sip:500@192.168.13.233:5060 [a318696b-d309-4724-abc6-1f0aca4f0dd3] 2012-11-08 21:18:21.169346 [DEBUG] mod_sofia.c:4879 (sofia/internal/sip:500@192.168.13.233:5060) State Change CS_NEW -> CS_INIT 2012-11-08 21:18:21.169346 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/sip:500@192.168.13.233:5060 [BREAK] 2012-11-08 21:18:21.169346 [DEBUG] mod_sofia.c:4954 [zrtp_passthru] Setting a-leg inherit_codec=true 2012-11-08 21:18:21.169346 [DEBUG] mod_sofia.c:4957 [zrtp_passthru] Setting b-leg absolute_codec_string='PCMU@8000h@20i@64000b,PCMA@8000h@20i@64000b' 2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/sip:500@192.168.13.233:5060) Running State Change CS_INIT 2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:437 (sofia/internal/sip:500@192.168.13.233:5060) State INIT 2012-11-08 21:18:21.169346 [DEBUG] mod_sofia.c:86 sofia/internal/sip:500@192.168.13.233:5060 SOFIA INIT 2012-11-08 21:18:21.169346 [DEBUG] sofia_glue.c:1920 sofia/internal/sip:500@192.168.13.233:5060 Patched SDP --- v=0 o=- 1352395099 1 IN IP4 192.168.13.71 s=VFT38M/v.25.08.2012 c=IN IP4 192.168.13.71 t=0 0 m=audio 5018 RTP/AVP 0 8 101 a=rtpmap:0 PCMU/8000/1 a=rtpmap:8 PCMA/8000/1 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16,32,36 a=maxptime:240 +++ v=0 o=FreeSWITCH 3287184146 3287184147 IN IP4 192.168.13.18 s=FreeSWITCH c=IN IP4 192.168.13.18 t=0 0 m=audio 16966 RTP/AVP 0 8 101 a=rtpmap:0 PCMU/8000/1 a=rtpmap:8 PCMA/8000/1 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16,32,36 a=maxptime:240 2012-11-08 21:18:21.169346 [DEBUG] sofia_glue.c:2637 Local SDP: v=0 o=FreeSWITCH 3287184146 3287184147 IN IP4 192.168.13.18 s=FreeSWITCH c=IN IP4 192.168.13.18 t=0 0 m=audio 16966 RTP/AVP 0 8 101 a=rtpmap:0 PCMU/8000/1 a=rtpmap:8 PCMA/8000/1 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16,32,36 a=maxptime:240 2012-11-08 21:18:21.169346 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/sip:500@192.168.13.233:5060 [BREAK] 2012-11-08 21:18:21.169346 [DEBUG] mod_sofia.c:126 (sofia/internal/sip:500@192.168.13.233:5060) State Change CS_INIT -> CS_ROUTING 2012-11-08 21:18:21.169346 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/sip:500@192.168.13.233:5060 [BREAK] 2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:437 (sofia/internal/sip:500@192.168.13.233:5060) State INIT going to sleep 2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/sip:500@192.168.13.233:5060) Running State Change CS_ROUTING 2012-11-08 21:18:21.169346 [DEBUG] switch_channel.c:1964 (sofia/internal/sip:500@192.168.13.233:5060) Callstate Change DOWN -> RINGING 2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:446 (sofia/internal/sip:500@192.168.13.233:5060) State ROUTING 2012-11-08 21:18:21.169346 [DEBUG] mod_sofia.c:149 sofia/internal/sip:500@192.168.13.233:5060 SOFIA ROUTING 2012-11-08 21:18:21.169346 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/sip:500@192.168.13.233:5060) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2012-11-08 21:18:21.169346 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/sip:500@192.168.13.233:5060 [BREAK] 2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:446 (sofia/internal/sip:500@192.168.13.233:5060) State ROUTING going to sleep 2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/sip:500@192.168.13.233:5060) Running State Change CS_CONSUME_MEDIA 2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:465 (sofia/internal/sip:500@192.168.13.233:5060) State CONSUME_MEDIA 2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:465 (sofia/internal/sip:500@192.168.13.233:5060) State CONSUME_MEDIA going to sleep 2012-11-08 21:18:21.169346 [DEBUG] sofia.c:6282 Channel sofia/internal/sip:500@192.168.13.233:5060 entering state [calling][0] 2012-11-08 21:18:53.169624 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/sip:500@192.168.13.233:5060 [BREAK] 2012-11-08 21:18:53.169624 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/sip:500@192.168.13.233:5060 [BREAK] 2012-11-08 21:18:53.169624 [DEBUG] sofia.c:6282 Channel sofia/internal/sip:500@192.168.13.233:5060 entering state [terminated][408] 2012-11-08 21:18:53.169624 [DEBUG] switch_channel.c:2950 (sofia/internal/sip:500@192.168.13.233:5060) Callstate Change RINGING -> HANGUP 2012-11-08 21:18:53.169624 [NOTICE] sofia.c:7082 Hangup sofia/internal/sip:500@192.168.13.233:5060 [CS_CONSUME_MEDIA] [RECOVERY_ON_TIMER_EXPIRE] 2012-11-08 21:18:53.169624 [DEBUG] switch_channel.c:2973 Send signal sofia/internal/sip:500@192.168.13.233:5060 [KILL] 2012-11-08 21:18:53.169624 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/sip:500@192.168.13.233:5060 [BREAK] 2012-11-08 21:18:53.169624 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/sip:500@192.168.13.233:5060) Running State Change CS_HANGUP 2012-11-08 21:18:53.169624 [DEBUG] switch_core_state_machine.c:638 (sofia/internal/sip:500@192.168.13.233:5060) State HANGUP 2012-11-08 21:18:53.169624 [DEBUG] mod_sofia.c:483 Channel sofia/internal/sip:500@192.168.13.233:5060 hanging up, cause: RECOVERY_ON_TIMER_EXPIRE 2012-11-08 21:18:53.169624 [DEBUG] switch_core_state_machine.c:48 sofia/internal/sip:500@192.168.13.233:5060 Standard HANGUP, cause: RECOVERY_ON_TIMER_EXPIRE 2012-11-08 21:18:53.169624 [DEBUG] switch_core_state_machine.c:638 (sofia/internal/sip:500@192.168.13.233:5060) State HANGUP going to sleep 2012-11-08 21:18:53.169624 [DEBUG] switch_core_state_machine.c:429 (sofia/internal/sip:500@192.168.13.233:5060) State Change CS_HANGUP -> CS_REPORTING 2012-11-08 21:18:53.169624 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/sip:500@192.168.13.233:5060 [BREAK] 2012-11-08 21:18:53.169624 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/sip:500@192.168.13.233:5060) Running State Change CS_REPORTING 2012-11-08 21:18:53.169624 [DEBUG] switch_core_state_machine.c:703 (sofia/internal/sip:500@192.168.13.233:5060) State REPORTING 2012-11-08 21:18:53.169624 [DEBUG] switch_core_state_machine.c:92 sofia/internal/sip:500@192.168.13.233:5060 Standard REPORTING, cause: RECOVERY_ON_TIMER_EXPIRE 2012-11-08 21:18:53.169624 [DEBUG] switch_core_state_machine.c:703 (sofia/internal/sip:500@192.168.13.233:5060) State REPORTING going to sleep 2012-11-08 21:18:53.169624 [DEBUG] switch_core_state_machine.c:423 (sofia/internal/sip:500@192.168.13.233:5060) State Change CS_REPORTING -> CS_DESTROY 2012-11-08 21:18:53.169624 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/sip:500@192.168.13.233:5060 [BREAK] 2012-11-08 21:18:53.169624 [DEBUG] switch_core_session.c:1415 Session 30 (sofia/internal/sip:500@192.168.13.233:5060) Locked, Waiting on external entities 2012-11-08 21:18:53.190125 [DEBUG] switch_ivr_originate.c:3508 Originate Resulted in Error Cause: 102 [RECOVERY_ON_TIMER_EXPIRE] 2012-11-08 21:18:53.190125 [NOTICE] switch_ivr_originate.c:2591 Cannot create outgoing channel of type [user] cause: [RECOVERY_ON_TIMER_EXPIRE] 2012-11-08 21:18:53.190125 [NOTICE] switch_core_session.c:1433 Session 30 (sofia/internal/sip:500@192.168.13.233:5060) Ended 2012-11-08 21:18:53.190125 [NOTICE] switch_core_session.c:1437 Close Channel sofia/internal/sip:500@192.168.13.233:5060 [CS_DESTROY] 2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:527 (sofia/internal/sip:500@192.168.13.233:5060) Callstate Change HANGUP -> DOWN 2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:530 (sofia/internal/sip:500@192.168.13.233:5060) Running State Change CS_DESTROY 2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:540 (sofia/internal/sip:500@192.168.13.233:5060) State DESTROY 2012-11-08 21:18:53.190125 [DEBUG] mod_sofia.c:376 sofia/internal/sip:500@192.168.13.233:5060 SOFIA DESTROY 2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:99 sofia/internal/sip:500@192.168.13.233:5060 Standard DESTROY 2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:540 (sofia/internal/sip:500@192.168.13.233:5060) State DESTROY going to sleep 2012-11-08 21:18:53.190125 [DEBUG] switch_ivr_originate.c:3508 Originate Resulted in Error Cause: 102 [RECOVERY_ON_TIMER_EXPIRE] 2012-11-08 21:18:53.190125 [INFO] mod_dptools.c:3027 Originate Failed. Cause: RECOVERY_ON_TIMER_EXPIRE 2012-11-08 21:18:53.190125 [DEBUG] switch_channel.c:2950 (sofia/internal/501(a)192.168.13.18) Callstate Change RINGING -> HANGUP 2012-11-08 21:18:53.190125 [NOTICE] mod_dptools.c:3147 Hangup sofia/internal/501(a)192.168.13.18 [CS_EXECUTE] [RECOVERY_ON_TIMER_EXPIRE] 2012-11-08 21:18:53.190125 [DEBUG] switch_channel.c:2973 Send signal sofia/internal/501(a)192.168.13.18 [KILL] 2012-11-08 21:18:53.190125 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/501(a)192.168.13.18 [BREAK] 2012-11-08 21:18:53.190125 [DEBUG] switch_core_session.c:2553 sofia/internal/501(a)192.168.13.18 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:453 (sofia/internal/501(a)192.168.13.18) State EXECUTE going to sleep 2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/501(a)192.168.13.18) Running State Change CS_HANGUP 2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:638 (sofia/internal/501(a)192.168.13.18) State HANGUP 2012-11-08 21:18:53.190125 [DEBUG] mod_sofia.c:477 sofia/internal/501(a)192.168.13.18 Overriding SIP cause 504 with 408 from the other leg 2012-11-08 21:18:53.190125 [DEBUG] mod_sofia.c:483 Channel sofia/internal/501(a)192.168.13.18 hanging up, cause: RECOVERY_ON_TIMER_EXPIRE 2012-11-08 21:18:53.190125 [DEBUG] mod_sofia.c:613 Responding to INVITE with: 408 2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:48 sofia/internal/501(a)192.168.13.18 Standard HANGUP, cause: RECOVERY_ON_TIMER_EXPIRE 2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:638 (sofia/internal/501(a)192.168.13.18) State HANGUP going to sleep 2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:429 (sofia/internal/501(a)192.168.13.18) State Change CS_HANGUP -> CS_REPORTING 2012-11-08 21:18:53.190125 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/501(a)192.168.13.18 [BREAK] 2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/501(a)192.168.13.18) Running State Change CS_REPORTING 2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:703 (sofia/internal/501(a)192.168.13.18) State REPORTING 2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:92 sofia/internal/501(a)192.168.13.18 Standard REPORTING, cause: RECOVERY_ON_TIMER_EXPIRE 2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:703 (sofia/internal/501(a)192.168.13.18) State REPORTING going to sleep 2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:423 (sofia/internal/501(a)192.168.13.18) State Change CS_REPORTING -> CS_DESTROY 2012-11-08 21:18:53.190125 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/501(a)192.168.13.18 [BREAK] 2012-11-08 21:18:53.190125 [DEBUG] switch_core_session.c:1415 Session 29 (sofia/internal/501(a)192.168.13.18) Locked, Waiting on external entities 2012-11-08 21:18:53.190125 [NOTICE] switch_core_session.c:1433 Session 29 (sofia/internal/501(a)192.168.13.18) Ended 2012-11-08 21:18:53.190125 [NOTICE] switch_core_session.c:1437 Close Channel sofia/internal/501(a)192.168.13.18 [CS_DESTROY] 2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:527 (sofia/internal/501(a)192.168.13.18) Callstate Change HANGUP -> DOWN 2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:530 (sofia/internal/501(a)192.168.13.18) Running State Change CS_DESTROY 2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:540 (sofia/internal/501(a)192.168.13.18) State DESTROY 2012-11-08 21:18:53.190125 [DEBUG] mod_sofia.c:376 sofia/internal/501(a)192.168.13.18 SOFIA DESTROY 2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:99 sofia/internal/501(a)192.168.13.18 Standard DESTROY 2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:540 (sofia/internal/501(a)192.168.13.18) State DESTROY going to sleep -- View this message in context: http://freeswitch-users.2379917.n2.nabble.com/problem-with-receiving-and-se… Sent from the freeswitch-users mailing list archive at Nabble.com.

2 4

how to force a fixed request timer on a gateway?
by Bret Watson 19 Nov '12

19 Nov '12

I think I've gotten to the root cause of the pennytel failure problems. Basically Pennytel is handing the wrong refresh time when my end makes the registration attempt. The first attempt if the box has been off for a day - always works, but not long afterwards its fails. with a series of 200 ok issues and finally a 400. It seems that freeswitch assumes Pennytel is asking for shorter and shorter refresh periods, and pennytel interprets my end do more frequent registrations as flooding and bans me. So I figure if I can override what Pennytel is sending with my own timeout period, it should stay happy - I've tried <param name="expire-seconds" value="360"/> but with no effect. Thanks Bret

1 0

Re: [Freeswitch-users] Error on Call Recording - Windows, FS V1.2.4
by Peter Olsson 19 Nov '12

19 Nov '12

It might be one of those Windows path things... Try using / instead of \ as a path separator. Both of them works in Windows, but FS probably only checks the "/" in the current code. Also, the only problem here is that if the directory wouldn't exist already, it would fail - besides that there is no real problem, except the error log message. /Peter Från: freeswitch-users-bounces(a)lists.freeswitch.org [mailto:freeswitch-users-bounces@lists.freeswitch.org] För Rob Moore Skickat: den 19 november 2012 12:51 Till: freeswitch-users(a)lists.freeswitch.org Ämne: [Freeswitch-users] Error on Call Recording - Windows, FS V1.2.4 Hi Everyone, Just a minor one here I'm checking on. Running the latest release of Freeswitch V1.2.4 (on Windows Server 2008R2, yes I know!) and running through some tests with our system that uses Lua scripts to request actions from the Server. Whilst recording calls I'm getting the following error, the call recording files is still created (or appended to if I choose to call this). 2012-11-19 11:29:22.666979 [ERR] switch_ivr_async.c:1840 Error finding the folder path section in 'C:\FreeSwitch\recordings\RobsTESTRecording5762fadd-7b5-8abf-e61cb1633827.wav' Does anyone have any idea what could be causing this? I've had a dig around in the documentation for switch_ivr_async.c. It looks like and error relating to a check on creating a directory but If I'm honest it's a little beyond my current skill set. Really I'm just trying to get shot of the error message and at the moment I'm a little stumped as to what could be causing this (although I wouldn't be surprised if it's the windows file system) Thanks in advanced Rob Rob Moore Telephony Systems Infrastructure Manager [Description: Aeriandi] m. +44 (0)7766 838 040 t. +44 (0)845 108 0308 Aeriandi Ltd / Prama House, 267 Banbury Road, Oxford OX2 7HT / +44 (0)845 108 0308 / info(a)aeriandi.com<mailto:info@aeriandi.com> / aeriandi.com<http://www.aeriandi.com/> This transmission is intended solely for the addressee and may be confidential. If you are not the named addressee, or if the message has been addressed to you in error, you must not read, disclose, reproduce, distribute or use this transmission. Please delete the message or contact the sender. Delivery of this message to any person other than the named addressee is not intended in any way to waive confidentiality. Please note that neither Aeriandi Ltd nor the sender accepts any responsibility for any viruses, which may be transmitted, and it is your responsibility to scan attachments (if any). !DSPAM:50aa21e332761953521012!

1 0

Re: [Freeswitch-users] Subscribe for MWI
by hiryu23 19 Nov '12

19 Nov '12

Hi Spencer I am configuring something similar. May i know what is your configuration for Kamailio for routing packets to FreeSwitch? Sorry i am pretty new here. Thanks in advance -- View this message in context: http://freeswitch-users.2379917.n2.nabble.com/Subscribe-for-MWI-tp7557448p7… Sent from the freeswitch-users mailing list archive at Nabble.com.

2 5

Logging
by David Villasmil 19 Nov '12

19 Nov '12

Hello guys, I'm going crazy with the logging feature. If I understand correctly, you set the minimum logging in switch.conf.xml, i.e.: debug. I set debug because I want to be able to do "console loglevel debug" for debugging later... but I don't want it all the time! FS is creating a log file every 2 minutes... I don't want that, I want to have "err" as the normal logging level and be able to do "debug" on the console whenever I need it... Is this possible? Thanks David

2 1

Packing for Mageia
by Luis Daniel Lucio Quiroz 18 Nov '12

18 Nov '12

Helo, I'm trying to pack FS for Mageia Linux, how ever i've some problems understanding release numbers. As my readings, wiki says that always get latest git snapshot as it is stable. But i wonder to know how to label releases, i mean 1.0.0, or 1.0.7 or 1.1beta2 ? Can you help me on where i can get this number from git? Regards, LD

3 4