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.