Hello! What is the device that is user 500? To use the dialplan like you have it now you'll need to have your fax device be registered to your FreeSWITCH server with user ID of "500". If you're using the example configs then this command will show the list of registered users: sofia status profile internal reg Make sure there really is a user 500 and that it can answer calls. Also, may I suggest that you avoid using loopback. In fact, you may wish to avoid using a dialplan entry altogether. You can specify all the items right at the command line: originate {fax_enable_t38=true,execute_on_answer='t38_gateway self'}user/500 &txfax(/tmp/txfax-sample.tiff) BTW, you shouldn't need to set proxy_media. Give it a try and let us know how it goes. -MC P.S. - I recommend that you put FS logs in pastebin.freeswitch.org and select "FreeSWITCH Log" as the syntax highlighting - it makes it much easier to read. On Thu, Nov 8, 2012 at 10:19 AM, sterned <sterned@xakep.ru> wrote:
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@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@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@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@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@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@192.168.13.18 [BREAK] 2012-11-08 21:18:21.129757 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/501@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@192.168.13.18) State NEW 2012-11-08 21:18:21.129757 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/501@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@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@192.168.13.18 [BREAK] 2012-11-08 21:18:21.149399 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/501@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@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@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@192.168.13.18 [BREAK] 2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/501@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@192.168.13.18) State INIT 2012-11-08 21:18:21.169346 [DEBUG] mod_sofia.c:86 sofia/internal/501@192.168.13.18 SOFIA INIT 2012-11-08 21:18:21.169346 [DEBUG] mod_sofia.c:126 (sofia/internal/501@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@192.168.13.18 [BREAK] 2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:437 (sofia/internal/501@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@192.168.13.18) Running State Change CS_ROUTING 2012-11-08 21:18:21.169346 [DEBUG] switch_channel.c:1964 (sofia/internal/501@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@192.168.13.18) State ROUTING 2012-11-08 21:18:21.169346 [DEBUG] mod_sofia.c:149 sofia/internal/501@192.168.13.18 SOFIA ROUTING 2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:117 sofia/internal/501@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@192.168.13.18 parsing [default->unloop] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->tod_example] continue=true Dialplan: sofia/internal/501@192.168.13.18 Date/TimeMatch (FAIL) [tod_example] break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->holiday_example] continue=true Dialplan: sofia/internal/501@192.168.13.18 Date/TimeMatch (FAIL) [holiday_example] break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->global-intercept] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [global-intercept] destination_number(500) =~ /^886$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->group-intercept] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [group-intercept] destination_number(500) =~ /^\*8$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->intercept-ext] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [intercept-ext] destination_number(500) =~ /^\*\*(\d+)$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->redial] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [redial] destination_number(500) =~ /^(redial|870)$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->global] continue=true Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never Dialplan: sofia/internal/501@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@192.168.13.18 Absolute Condition [global] Dialplan: sofia/internal/501@192.168.13.18 Action hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid}) Dialplan: sofia/internal/501@192.168.13.18 Action
hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number}) Dialplan: sofia/internal/501@192.168.13.18 Action hash(insert/${domain_name}-last_dial/global/${uuid}) Dialplan: sofia/internal/501@192.168.13.18 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) Dialplan: sofia/internal/501@192.168.13.18 parsing [default->snom-demo-2] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [snom-demo-2] destination_number(500) =~ /^9001$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->snom-demo-1] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [snom-demo-1] destination_number(500) =~ /^9000$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->eavesdrop] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [eavesdrop] destination_number(500) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->eavesdrop] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [eavesdrop] destination_number(500) =~ /^779$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->call_return] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [call_return] destination_number(500) =~ /^\*69$|^869$|^lcr$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->del-group] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [del-group] destination_number(500) =~ /^80(\d{2})$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->add-group] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [add-group] destination_number(500) =~ /^81(\d{2})$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->call-group-simo] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [call-group-simo] destination_number(500) =~ /^82(\d{2})$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->call-group-order] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [call-group-order] destination_number(500) =~ /^83(\d{2})$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->extension-intercom] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [extension-intercom] destination_number(500) =~ /^8(10[01][0-9])$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->Local_Extension] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [Local_Extension] destination_number(500) =~ /^(10[01][0-9])$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->Local_Extension_Skinny] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [Local_Extension_Skinny] destination_number(500) =~ /^(11[01][0-9])$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->group_dial_sales] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [group_dial_sales] destination_number(500) =~ /^2000$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->group_dial_support] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [group_dial_support] destination_number(500) =~ /^2001$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->group_dial_billing] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [group_dial_billing] destination_number(500) =~ /^2002$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->operator] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [operator] destination_number(500) =~ /^(operator|0)$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->vmain] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [vmain] destination_number(500) =~ /^vmain$|^4000$|^\*98$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->sip_uri] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [sip_uri] destination_number(500) =~ /^sip:(.*)$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->nb_conferences] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [nb_conferences] destination_number(500) =~ /^(30\d{2})$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->wb_conferences] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [wb_conferences] destination_number(500) =~ /^(31\d{2})$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->uwb_conferences] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [uwb_conferences] destination_number(500) =~ /^(32\d{2})$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->cdquality_conferences] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [cdquality_conferences] destination_number(500) =~ /^(33\d{2})$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->freeswitch_public_conf_via_sip] continue=false Dialplan: sofia/internal/501@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@192.168.13.18 parsing [default->mad_boss_intercom] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [mad_boss_intercom] destination_number(500) =~ /^0911$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->mad_boss_intercom] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [mad_boss_intercom] destination_number(500) =~ /^0912$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->mad_boss] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [mad_boss] destination_number(500) =~ /^0913$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->ivr_demo] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [ivr_demo] destination_number(500) =~ /^5000$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->dynamic_conference] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [dynamic_conference] destination_number(500) =~ /^5001$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->rtp_multicast_page] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [rtp_multicast_page] destination_number(500) =~ /^pagegroup$|^7243$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->park] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [park] destination_number(500) =~ /^5900$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->unpark] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [unpark] destination_number(500) =~ /^5901$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->valet_park] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [valet_park] destination_number(500) =~ /^(6000)$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->valet_park] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [valet_park] destination_number(500) =~ /^(60\d[1-9])$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->park] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (PASS) [park] source(mod_sofia) =~ /mod_sofia/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [park] destination_number(500) =~ /park\+(\d+)/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->unpark] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (PASS) [unpark] source(mod_sofia) =~ /mod_sofia/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [unpark] destination_number(500) =~ /^parking$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->park] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (PASS) [park] source(mod_sofia) =~ /mod_sofia/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [park] destination_number(500) =~ /callpark/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->unpark] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (PASS) [unpark] source(mod_sofia) =~ /mod_sofia/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [unpark] destination_number(500) =~ /pickup/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->wait] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [wait] destination_number(500) =~ /^wait$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->fax_receive] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [fax_receive] destination_number(500) =~ /^9178$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->fax_transmit] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [fax_transmit] destination_number(500) =~ /^9179$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->ringback_180] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [ringback_180] destination_number(500) =~ /^9180$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->ringback_183_uk_ring] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [ringback_183_uk_ring] destination_number(500) =~ /^9181$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->ringback_183_music_ring] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [ringback_183_music_ring] destination_number(500) =~ /^9182$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->ringback_post_answer_uk_ring] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [ringback_post_answer_uk_ring] destination_number(500) =~ /^9183$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->ringback_post_answer_music] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [ringback_post_answer_music] destination_number(500) =~ /^9184$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->ClueCon] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [ClueCon] destination_number(500) =~ /^9191$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->show_info] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [show_info] destination_number(500) =~ /^9192$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->video_record] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [video_record] destination_number(500) =~ /^9193$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->video_playback] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [video_playback] destination_number(500) =~ /^9194$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->delay_echo] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [delay_echo] destination_number(500) =~ /^9195$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->echo] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [echo] destination_number(500) =~ /^9196$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->milliwatt] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [milliwatt] destination_number(500) =~ /^9197$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->tone_stream] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [tone_stream] destination_number(500) =~ /^9198$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->zrtp_enrollement] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [zrtp_enrollement] destination_number(500) =~ /^9787$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->hold_music] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [hold_music] destination_number(500) =~ /^9664$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->laugh break] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [laugh break] destination_number(500) =~ /^9386$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->5555555] continue=false Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [5555555] destination_number(500) =~ /^(1000)$/ break=on-false Dialplan: sofia/internal/501@192.168.13.18 parsing [default->fax] continue=false Dialplan: sofia/internal/501@192.168.13.18 Absolute Condition [fax] Dialplan: sofia/internal/501@192.168.13.18 Action set(fax_enable_t38=true) Dialplan: sofia/internal/501@192.168.13.18 Action set(execute_on_answer=t38_gateway self) Dialplan: sofia/internal/501@192.168.13.18 Action set(proxy_media=true) Dialplan: sofia/internal/501@192.168.13.18 Action bridge(user/500@192.168.13.18) 2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:167 (sofia/internal/501@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@192.168.13.18 [BREAK] 2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:446 (sofia/internal/501@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@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@192.168.13.18) State EXECUTE 2012-11-08 21:18:21.169346 [DEBUG] mod_sofia.c:242 sofia/internal/501@192.168.13.18 SOFIA EXECUTE 2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:209 sofia/internal/501@192.168.13.18 Standard EXECUTE EXECUTE sofia/internal/501@192.168.13.18 hash(insert/192.168.13.18-spymap/501/ce35cc96-6ce5-4cf7-a9f0-71f7d31e454d) EXECUTE sofia/internal/501@192.168.13.18 hash(insert/192.168.13.18-last_dial/501/500) EXECUTE sofia/internal/501@192.168.13.18
hash(insert/192.168.13.18-last_dial/global/ce35cc96-6ce5-4cf7-a9f0-71f7d31e454d) EXECUTE sofia/internal/501@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@192.168.13.18 set(fax_enable_t38=true) 2012-11-08 21:18:21.169346 [DEBUG] mod_dptools.c:1319 sofia/internal/501@192.168.13.18 SET [fax_enable_t38]=[true] EXECUTE sofia/internal/501@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@192.168.13.18 SET [execute_on_answer]=[t38_gateway self] EXECUTE sofia/internal/501@192.168.13.18 set(proxy_media=true) 2012-11-08 21:18:21.169346 [DEBUG] mod_dptools.c:1319 sofia/internal/501@192.168.13.18 SET [proxy_media]=[true] EXECUTE sofia/internal/501@192.168.13.18 bridge(user/500@192.168.13.18) 2012-11-08 21:18:21.169346 [DEBUG] switch_channel.c:1072 sofia/internal/501@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@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@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@192.168.13.18) Callstate Change RINGING -> HANGUP 2012-11-08 21:18:53.190125 [NOTICE] mod_dptools.c:3147 Hangup sofia/internal/501@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@192.168.13.18 [KILL] 2012-11-08 21:18:53.190125 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/501@192.168.13.18 [BREAK] 2012-11-08 21:18:53.190125 [DEBUG] switch_core_session.c:2553 sofia/internal/501@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@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@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@192.168.13.18) State HANGUP 2012-11-08 21:18:53.190125 [DEBUG] mod_sofia.c:477 sofia/internal/501@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@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@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@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@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@192.168.13.18 [BREAK] 2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/501@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@192.168.13.18) State REPORTING 2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:92 sofia/internal/501@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@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@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@192.168.13.18 [BREAK] 2012-11-08 21:18:53.190125 [DEBUG] switch_core_session.c:1415 Session 29 (sofia/internal/501@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@192.168.13.18) Ended 2012-11-08 21:18:53.190125 [NOTICE] switch_core_session.c:1437 Close Channel sofia/internal/501@192.168.13.18 [CS_DESTROY] 2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:527 (sofia/internal/501@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@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@192.168.13.18) State DESTROY 2012-11-08 21:18:53.190125 [DEBUG] mod_sofia.c:376 sofia/internal/501@192.168.13.18 SOFIA DESTROY 2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:99 sofia/internal/501@192.168.13.18 Standard DESTROY 2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:540 (sofia/internal/501@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-sen... Sent from the freeswitch-users mailing list archive at Nabble.com.
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com
FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com
Official FreeSWITCH Sites http://www.freeswitch.org http://wiki.freeswitch.org http://www.cluecon.com
FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
-- Michael S Collins Twitter: @mercutioviz http://www.FreeSWITCH.org http://www.ClueCon.com http://www.OSTAG.org