[Freeswitch-users] problem with receiving and sending faxes
Michael Collins
msc at freeswitch.org
Mon Nov 12 20:55:25 MSK 2012
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 at 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 at 192.168.13.18"/>
> </condition>
> </extension>
> log:
> freeswitch at 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 at 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 at 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 at 192.168.13.18]
> 2012-11-08 21:21:08.409369 [NOTICE] switch_channel.c:951 New Channel
> sofia/internal/sip:500 at 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 at 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 at 192.168.13.233:5060 [BREAK]
> 2012-11-08 21:21:08.429387 [DEBUG] switch_core_state_machine.c:398
> (sofia/internal/sip:500 at 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 at 192.168.13.233:5060) State INIT
> 2012-11-08 21:21:08.429387 [DEBUG] mod_sofia.c:86
> sofia/internal/sip:500 at 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 at 192.168.13.233:5060 [BREAK]
> 2012-11-08 21:21:08.429387 [DEBUG] mod_sofia.c:126
> (sofia/internal/sip:500 at 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 at 192.168.13.233:5060 [BREAK]
> 2012-11-08 21:21:08.429387 [DEBUG] switch_core_state_machine.c:437
> (sofia/internal/sip:500 at 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 at 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 at 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 at 192.168.13.233:5060) State ROUTING
> 2012-11-08 21:21:08.429387 [DEBUG] mod_sofia.c:149
> sofia/internal/sip:500 at 192.168.13.233:5060 SOFIA ROUTING
> 2012-11-08 21:21:08.429387 [DEBUG] switch_ivr_originate.c:67
> (sofia/internal/sip:500 at 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 at 192.168.13.233:5060 [BREAK]
> 2012-11-08 21:21:08.429387 [DEBUG] switch_core_state_machine.c:446
> (sofia/internal/sip:500 at 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 at 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 at 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 at 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 at 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 at 192.168.13.233:5060 [BREAK]
> 2012-11-08 21:21:29.609239 [DEBUG] switch_channel.c:2950
> (sofia/internal/sip:500 at 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 at 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 at 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 at 192.168.13.233:5060 [BREAK]
> 2012-11-08 21:21:29.609239 [DEBUG] switch_core_state_machine.c:398
> (sofia/internal/sip:500 at 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 at 192.168.13.233:5060) State HANGUP
> 2012-11-08 21:21:29.609239 [DEBUG] mod_sofia.c:483 Channel
> sofia/internal/sip:500 at 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 at 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 at 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 at 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 at 192.168.13.233:5060 [BREAK]
> 2012-11-08 21:21:29.609239 [DEBUG] switch_core_state_machine.c:398
> (sofia/internal/sip:500 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 192.168.13.233:5060) State DESTROY
> 2012-11-08 21:21:29.629589 [DEBUG] mod_sofia.c:376
> sofia/internal/sip:500 at 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 at 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 at 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 at 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 at 192.168.13.18 [BREAK]
> 2012-11-08 21:18:21.129757 [DEBUG] switch_core_state_machine.c:398
> (sofia/internal/501 at 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 at 192.168.13.18) State NEW
> 2012-11-08 21:18:21.129757 [DEBUG] switch_core_session.c:905 Send signal
> sofia/internal/501 at 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 at 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 at 192.168.13.18 [BREAK]
> 2012-11-08 21:18:21.149399 [DEBUG] switch_core_session.c:905 Send signal
> sofia/internal/501 at 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 at 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 at 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 at 192.168.13.18 [BREAK]
> 2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:398
> (sofia/internal/501 at 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 at 192.168.13.18) State INIT
> 2012-11-08 21:18:21.169346 [DEBUG] mod_sofia.c:86
> sofia/internal/501 at 192.168.13.18 SOFIA INIT
> 2012-11-08 21:18:21.169346 [DEBUG] mod_sofia.c:126
> (sofia/internal/501 at 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 at 192.168.13.18 [BREAK]
> 2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:437
> (sofia/internal/501 at 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 at 192.168.13.18) Running State Change CS_ROUTING
> 2012-11-08 21:18:21.169346 [DEBUG] switch_channel.c:1964
> (sofia/internal/501 at 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 at 192.168.13.18) State ROUTING
> 2012-11-08 21:18:21.169346 [DEBUG] mod_sofia.c:149
> sofia/internal/501 at 192.168.13.18 SOFIA ROUTING
> 2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:117
> sofia/internal/501 at 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 at 192.168.13.18 parsing [default->unloop]
> continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (PASS) [unloop]
> ${unroll_loops}(true) =~ /^true$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL) [unloop]
> ${sip_looped_call}() =~ /^true$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing [default->tod_example]
> continue=true
> Dialplan: sofia/internal/501 at 192.168.13.18 Date/TimeMatch (FAIL)
> [tod_example] break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing
> [default->holiday_example] continue=true
> Dialplan: sofia/internal/501 at 192.168.13.18 Date/TimeMatch (FAIL)
> [holiday_example] break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing
> [default->global-intercept] continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL) [global-intercept]
> destination_number(500) =~ /^886$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing
> [default->group-intercept] continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL) [group-intercept]
> destination_number(500) =~ /^\*8$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing
> [default->intercept-ext]
> continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL) [intercept-ext]
> destination_number(500) =~ /^\*\*(\d+)$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing [default->redial]
> continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL) [redial]
> destination_number(500) =~ /^(redial|870)$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing [default->global]
> continue=true
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL) [global]
> ${call_debug}(false) =~ /^true$/ break=never
> Dialplan: sofia/internal/501 at 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 at 192.168.13.18 Absolute Condition [global]
> Dialplan: sofia/internal/501 at 192.168.13.18 Action
> hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid})
> Dialplan: sofia/internal/501 at 192.168.13.18 Action
>
> hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
> Dialplan: sofia/internal/501 at 192.168.13.18 Action
> hash(insert/${domain_name}-last_dial/global/${uuid})
> Dialplan: sofia/internal/501 at 192.168.13.18 Action
> export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing [default->snom-demo-2]
> continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL) [snom-demo-2]
> destination_number(500) =~ /^9001$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing [default->snom-demo-1]
> continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL) [snom-demo-1]
> destination_number(500) =~ /^9000$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing [default->eavesdrop]
> continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL) [eavesdrop]
> destination_number(500) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing [default->eavesdrop]
> continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL) [eavesdrop]
> destination_number(500) =~ /^779$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing [default->call_return]
> continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL) [call_return]
> destination_number(500) =~ /^\*69$|^869$|^lcr$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing [default->del-group]
> continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL) [del-group]
> destination_number(500) =~ /^80(\d{2})$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing [default->add-group]
> continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL) [add-group]
> destination_number(500) =~ /^81(\d{2})$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing
> [default->call-group-simo] continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL) [call-group-simo]
> destination_number(500) =~ /^82(\d{2})$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing
> [default->call-group-order] continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL) [call-group-order]
> destination_number(500) =~ /^83(\d{2})$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing
> [default->extension-intercom] continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL)
> [extension-intercom]
> destination_number(500) =~ /^8(10[01][0-9])$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing
> [default->Local_Extension] continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL) [Local_Extension]
> destination_number(500) =~ /^(10[01][0-9])$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing
> [default->Local_Extension_Skinny] continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL)
> [Local_Extension_Skinny] destination_number(500) =~ /^(11[01][0-9])$/
> break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing
> [default->group_dial_sales] continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL) [group_dial_sales]
> destination_number(500) =~ /^2000$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing
> [default->group_dial_support] continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL)
> [group_dial_support]
> destination_number(500) =~ /^2001$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing
> [default->group_dial_billing] continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL)
> [group_dial_billing]
> destination_number(500) =~ /^2002$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing [default->operator]
> continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL) [operator]
> destination_number(500) =~ /^(operator|0)$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing [default->vmain]
> continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL) [vmain]
> destination_number(500) =~ /^vmain$|^4000$|^\*98$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing [default->sip_uri]
> continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL) [sip_uri]
> destination_number(500) =~ /^sip:(.*)$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing
> [default->nb_conferences]
> continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL) [nb_conferences]
> destination_number(500) =~ /^(30\d{2})$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing
> [default->wb_conferences]
> continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL) [wb_conferences]
> destination_number(500) =~ /^(31\d{2})$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing
> [default->uwb_conferences] continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL) [uwb_conferences]
> destination_number(500) =~ /^(32\d{2})$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing
> [default->cdquality_conferences] continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL)
> [cdquality_conferences] destination_number(500) =~ /^(33\d{2})$/
> break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing
> [default->freeswitch_public_conf_via_sip] continue=false
> Dialplan: sofia/internal/501 at 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 at 192.168.13.18 parsing
> [default->mad_boss_intercom] continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL)
> [mad_boss_intercom]
> destination_number(500) =~ /^0911$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing
> [default->mad_boss_intercom] continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL)
> [mad_boss_intercom]
> destination_number(500) =~ /^0912$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing [default->mad_boss]
> continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL) [mad_boss]
> destination_number(500) =~ /^0913$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing [default->ivr_demo]
> continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL) [ivr_demo]
> destination_number(500) =~ /^5000$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing
> [default->dynamic_conference] continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL)
> [dynamic_conference]
> destination_number(500) =~ /^5001$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing
> [default->rtp_multicast_page] continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL)
> [rtp_multicast_page]
> destination_number(500) =~ /^pagegroup$|^7243$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing [default->park]
> continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL) [park]
> destination_number(500) =~ /^5900$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing [default->unpark]
> continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL) [unpark]
> destination_number(500) =~ /^5901$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing [default->valet_park]
> continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL) [valet_park]
> destination_number(500) =~ /^(6000)$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing [default->valet_park]
> continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL) [valet_park]
> destination_number(500) =~ /^(60\d[1-9])$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing [default->park]
> continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (PASS) [park]
> source(mod_sofia) =~ /mod_sofia/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL) [park]
> destination_number(500) =~ /park\+(\d+)/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing [default->unpark]
> continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (PASS) [unpark]
> source(mod_sofia) =~ /mod_sofia/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL) [unpark]
> destination_number(500) =~ /^parking$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing [default->park]
> continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (PASS) [park]
> source(mod_sofia) =~ /mod_sofia/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL) [park]
> destination_number(500) =~ /callpark/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing [default->unpark]
> continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (PASS) [unpark]
> source(mod_sofia) =~ /mod_sofia/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL) [unpark]
> destination_number(500) =~ /pickup/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing [default->wait]
> continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL) [wait]
> destination_number(500) =~ /^wait$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing [default->fax_receive]
> continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL) [fax_receive]
> destination_number(500) =~ /^9178$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing [default->fax_transmit]
> continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL) [fax_transmit]
> destination_number(500) =~ /^9179$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing [default->ringback_180]
> continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL) [ringback_180]
> destination_number(500) =~ /^9180$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing
> [default->ringback_183_uk_ring] continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL)
> [ringback_183_uk_ring] destination_number(500) =~ /^9181$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing
> [default->ringback_183_music_ring] continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL)
> [ringback_183_music_ring] destination_number(500) =~ /^9182$/
> break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing
> [default->ringback_post_answer_uk_ring] continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL)
> [ringback_post_answer_uk_ring] destination_number(500) =~ /^9183$/
> break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing
> [default->ringback_post_answer_music] continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL)
> [ringback_post_answer_music] destination_number(500) =~ /^9184$/
> break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing [default->ClueCon]
> continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL) [ClueCon]
> destination_number(500) =~ /^9191$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing [default->show_info]
> continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL) [show_info]
> destination_number(500) =~ /^9192$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing [default->video_record]
> continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL) [video_record]
> destination_number(500) =~ /^9193$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing
> [default->video_playback]
> continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL) [video_playback]
> destination_number(500) =~ /^9194$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing [default->delay_echo]
> continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL) [delay_echo]
> destination_number(500) =~ /^9195$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing [default->echo]
> continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL) [echo]
> destination_number(500) =~ /^9196$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing [default->milliwatt]
> continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL) [milliwatt]
> destination_number(500) =~ /^9197$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing [default->tone_stream]
> continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL) [tone_stream]
> destination_number(500) =~ /^9198$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing
> [default->zrtp_enrollement] continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL) [zrtp_enrollement]
> destination_number(500) =~ /^9787$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing [default->hold_music]
> continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL) [hold_music]
> destination_number(500) =~ /^9664$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing [default->laugh break]
> continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL) [laugh break]
> destination_number(500) =~ /^9386$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing [default->5555555]
> continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Regex (FAIL) [5555555]
> destination_number(500) =~ /^(1000)$/ break=on-false
> Dialplan: sofia/internal/501 at 192.168.13.18 parsing [default->fax]
> continue=false
> Dialplan: sofia/internal/501 at 192.168.13.18 Absolute Condition [fax]
> Dialplan: sofia/internal/501 at 192.168.13.18 Action set(fax_enable_t38=true)
> Dialplan: sofia/internal/501 at 192.168.13.18 Action
> set(execute_on_answer=t38_gateway self)
> Dialplan: sofia/internal/501 at 192.168.13.18 Action set(proxy_media=true)
> Dialplan: sofia/internal/501 at 192.168.13.18 Action
> bridge(user/500 at 192.168.13.18)
> 2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:167
> (sofia/internal/501 at 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 at 192.168.13.18 [BREAK]
> 2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:446
> (sofia/internal/501 at 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 at 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 at 192.168.13.18) State EXECUTE
> 2012-11-08 21:18:21.169346 [DEBUG] mod_sofia.c:242
> sofia/internal/501 at 192.168.13.18 SOFIA EXECUTE
> 2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:209
> sofia/internal/501 at 192.168.13.18 Standard EXECUTE
> EXECUTE sofia/internal/501 at 192.168.13.18
> hash(insert/192.168.13.18-spymap/501/ce35cc96-6ce5-4cf7-a9f0-71f7d31e454d)
> EXECUTE sofia/internal/501 at 192.168.13.18
> hash(insert/192.168.13.18-last_dial/501/500)
> EXECUTE sofia/internal/501 at 192.168.13.18
>
> hash(insert/192.168.13.18-last_dial/global/ce35cc96-6ce5-4cf7-a9f0-71f7d31e454d)
> EXECUTE sofia/internal/501 at 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 at 192.168.13.18 set(fax_enable_t38=true)
> 2012-11-08 21:18:21.169346 [DEBUG] mod_dptools.c:1319
> sofia/internal/501 at 192.168.13.18 SET [fax_enable_t38]=[true]
> EXECUTE sofia/internal/501 at 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 at 192.168.13.18 SET [execute_on_answer]=[t38_gateway
> self]
> EXECUTE sofia/internal/501 at 192.168.13.18 set(proxy_media=true)
> 2012-11-08 21:18:21.169346 [DEBUG] mod_dptools.c:1319
> sofia/internal/501 at 192.168.13.18 SET [proxy_media]=[true]
> EXECUTE sofia/internal/501 at 192.168.13.18 bridge(user/500 at 192.168.13.18)
> 2012-11-08 21:18:21.169346 [DEBUG] switch_channel.c:1072
> sofia/internal/501 at 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 at 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 at 192.168.13.18]
> 2012-11-08 21:18:21.169346 [NOTICE] switch_channel.c:951 New Channel
> sofia/internal/sip:500 at 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 at 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 at 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 at 8000h@20i at 64000b,PCMA at 8000h@20i at 64000b'
> 2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:398
> (sofia/internal/sip:500 at 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 at 192.168.13.233:5060) State INIT
> 2012-11-08 21:18:21.169346 [DEBUG] mod_sofia.c:86
> sofia/internal/sip:500 at 192.168.13.233:5060 SOFIA INIT
> 2012-11-08 21:18:21.169346 [DEBUG] sofia_glue.c:1920
> sofia/internal/sip:500 at 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 at 192.168.13.233:5060 [BREAK]
> 2012-11-08 21:18:21.169346 [DEBUG] mod_sofia.c:126
> (sofia/internal/sip:500 at 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 at 192.168.13.233:5060 [BREAK]
> 2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:437
> (sofia/internal/sip:500 at 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 at 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 at 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 at 192.168.13.233:5060) State ROUTING
> 2012-11-08 21:18:21.169346 [DEBUG] mod_sofia.c:149
> sofia/internal/sip:500 at 192.168.13.233:5060 SOFIA ROUTING
> 2012-11-08 21:18:21.169346 [DEBUG] switch_ivr_originate.c:67
> (sofia/internal/sip:500 at 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 at 192.168.13.233:5060 [BREAK]
> 2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:446
> (sofia/internal/sip:500 at 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 at 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 at 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 at 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 at 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 at 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 at 192.168.13.233:5060 [BREAK]
> 2012-11-08 21:18:53.169624 [DEBUG] sofia.c:6282 Channel
> sofia/internal/sip:500 at 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 at 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 at 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 at 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 at 192.168.13.233:5060 [BREAK]
> 2012-11-08 21:18:53.169624 [DEBUG] switch_core_state_machine.c:398
> (sofia/internal/sip:500 at 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 at 192.168.13.233:5060) State HANGUP
> 2012-11-08 21:18:53.169624 [DEBUG] mod_sofia.c:483 Channel
> sofia/internal/sip:500 at 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 at 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 at 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 at 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 at 192.168.13.233:5060 [BREAK]
> 2012-11-08 21:18:53.169624 [DEBUG] switch_core_state_machine.c:398
> (sofia/internal/sip:500 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 192.168.13.233:5060) State DESTROY
> 2012-11-08 21:18:53.190125 [DEBUG] mod_sofia.c:376
> sofia/internal/sip:500 at 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 at 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 at 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 at 192.168.13.18) Callstate Change RINGING -> HANGUP
> 2012-11-08 21:18:53.190125 [NOTICE] mod_dptools.c:3147 Hangup
> sofia/internal/501 at 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 at 192.168.13.18 [KILL]
> 2012-11-08 21:18:53.190125 [DEBUG] switch_core_session.c:1210 Send signal
> sofia/internal/501 at 192.168.13.18 [BREAK]
> 2012-11-08 21:18:53.190125 [DEBUG] switch_core_session.c:2553
> sofia/internal/501 at 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 at 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 at 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 at 192.168.13.18) State HANGUP
> 2012-11-08 21:18:53.190125 [DEBUG] mod_sofia.c:477
> sofia/internal/501 at 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 at 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 at 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 at 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 at 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 at 192.168.13.18 [BREAK]
> 2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:398
> (sofia/internal/501 at 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 at 192.168.13.18) State REPORTING
> 2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:92
> sofia/internal/501 at 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 at 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 at 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 at 192.168.13.18 [BREAK]
> 2012-11-08 21:18:53.190125 [DEBUG] switch_core_session.c:1415 Session 29
> (sofia/internal/501 at 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 at 192.168.13.18) Ended
> 2012-11-08 21:18:53.190125 [NOTICE] switch_core_session.c:1437 Close
> Channel
> sofia/internal/501 at 192.168.13.18 [CS_DESTROY]
> 2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:527
> (sofia/internal/501 at 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 at 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 at 192.168.13.18) State DESTROY
> 2012-11-08 21:18:53.190125 [DEBUG] mod_sofia.c:376
> sofia/internal/501 at 192.168.13.18 SOFIA DESTROY
> 2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:99
> sofia/internal/501 at 192.168.13.18 Standard DESTROY
> 2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:540
> (sofia/internal/501 at 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-sending-faxes-tp7584436.html
> Sent from the freeswitch-users mailing list archive at Nabble.com.
>
> _________________________________________________________________________
> Professional FreeSWITCH Consulting Services:
> consulting at freeswitch.org
> http://www.freeswitchsolutions.com
>
>
>
>
> Official FreeSWITCH Sites
> http://www.freeswitch.org
> http://wiki.freeswitch.org
> http://www.cluecon.com
>
> FreeSWITCH-users mailing list
> FreeSWITCH-users at lists.freeswitch.org
> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
> http://www.freeswitch.org
>
--
Michael S Collins
Twitter: @mercutioviz
http://www.FreeSWITCH.org
http://www.ClueCon.com
http://www.OSTAG.org
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20121112/65af04ff/attachment-0001.html
Join us at ClueCon 2011 Aug 9-11, 2011
More information about the FreeSWITCH-users
mailing list