Hello!

What is the device that is user 500? To use the dialplan like you have it now you'll need to have your fax device be registered to your FreeSWITCH server with user ID of "500". If you're using the example configs then this command will show the list of registered users:

sofia status profile internal reg

Make sure there really is a user 500 and that it can answer calls. Also, may I suggest that you avoid using loopback. In fact, you may wish to avoid using a dialplan entry altogether. You can specify all the items right at the command line:

originate {fax_enable_t38=true,execute_on_answer='t38_gateway self'}user/500 &txfax(/tmp/txfax-sample.tiff)

BTW, you shouldn't need to set proxy_media. Give it a try and let us know how it goes.

-MC

P.S. - I recommend that you put FS logs in pastebin.freeswitch.org and select "FreeSWITCH Log" as the syntax highlighting - it makes it much easier to read.

On Thu, Nov 8, 2012 at 10:19 AM, sterned <sterned@xakep.ru> wrote:
Hello Please help me with the fax. I created a user 500 and 501. created a
dialplan for 500 and am trying to send a fax from the server command:
freeswitch @ internal> originate loopback/500 & txfax (/ tmp /
txfax-sample.tiff)
use: soft fax Venta Fax&Voice
dialplan:
<extension name="fax">
  <condition>
     <action application="set" data="fax_enable_t38=true"/>
    <action application="set" data="execute_on_answer=t38_gateway self"/>
    <action application="set" data="proxy_media=true" />
      <action application="bridge" data="user/500@192.168.13.18"/>
  </condition>
</extension>
log:
freeswitch@internal> originate loopback/500 &txfax(/tmp/txfax-sample.tiff)
-ERR NORMAL_CLEARING

2012-11-08 21:21:08.409369 [DEBUG] switch_ivr_originate.c:2005 Parsing
global variables
2012-11-08 21:21:08.409369 [NOTICE] switch_channel.c:951 New Channel
loopback/500-a [c2807b1f-acac-4e17-9271-6cf5c61000f2]
2012-11-08 21:21:08.409369 [DEBUG] mod_loopback.c:154 loopback/500-a setup
codec L16/8000/20
2012-11-08 21:21:08.409369 [NOTICE] switch_channel.c:949 Rename Channel
loopback/500-a->loopback/500-a [c2807b1f-acac-4e17-9271-6cf5c61000f2]
2012-11-08 21:21:08.409369 [DEBUG] mod_loopback.c:1069 (loopback/500-a)
State Change CS_NEW -> CS_INIT
2012-11-08 21:21:08.409369 [DEBUG] switch_core_session.c:1210 Send signal
loopback/500-a [BREAK]
2012-11-08 21:21:08.409369 [DEBUG] mod_loopback.c:501 loopback/500-a CHANNEL
KILL
2012-11-08 21:21:08.409369 [DEBUG] switch_core_state_machine.c:398
(loopback/500-a) Running State Change CS_INIT
2012-11-08 21:21:08.409369 [DEBUG] switch_core_state_machine.c:437
(loopback/500-a) State INIT
2012-11-08 21:21:08.409369 [NOTICE] switch_channel.c:951 New Channel
loopback/500-b [d3de53aa-7a3e-483b-bd3f-434eba87815b]
2012-11-08 21:21:08.409369 [DEBUG] mod_loopback.c:154 loopback/500-b setup
codec L16/8000/20
2012-11-08 21:21:08.409369 [DEBUG] mod_loopback.c:268 (loopback/500-b) State
Change CS_NEW -> CS_INIT
2012-11-08 21:21:08.409369 [DEBUG] switch_core_session.c:1210 Send signal
loopback/500-b [BREAK]
2012-11-08 21:21:08.409369 [DEBUG] mod_loopback.c:501 loopback/500-b CHANNEL
KILL
2012-11-08 21:21:08.409369 [DEBUG] mod_loopback.c:324 (loopback/500-a) State
Change CS_INIT -> CS_ROUTING
2012-11-08 21:21:08.409369 [DEBUG] switch_core_session.c:1210 Send signal
loopback/500-a [BREAK]
2012-11-08 21:21:08.409369 [DEBUG] mod_loopback.c:501 loopback/500-a CHANNEL
KILL
2012-11-08 21:21:08.409369 [DEBUG] switch_core_state_machine.c:437
(loopback/500-a) State INIT going to sleep
2012-11-08 21:21:08.409369 [DEBUG] switch_core_state_machine.c:398
(loopback/500-a) Running State Change CS_ROUTING
2012-11-08 21:21:08.409369 [DEBUG] switch_channel.c:1964 (loopback/500-a)
Callstate Change DOWN -> RINGING
2012-11-08 21:21:08.409369 [DEBUG] switch_core_state_machine.c:446
(loopback/500-a) State ROUTING
2012-11-08 21:21:08.409369 [DEBUG] mod_loopback.c:356 loopback/500-a CHANNEL
ROUTING
2012-11-08 21:21:08.409369 [DEBUG] switch_ivr_originate.c:67
(loopback/500-a) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2012-11-08 21:21:08.409369 [DEBUG] switch_core_session.c:1210 Send signal
loopback/500-a [BREAK]
2012-11-08 21:21:08.409369 [DEBUG] mod_loopback.c:501 loopback/500-a CHANNEL
KILL
2012-11-08 21:21:08.409369 [DEBUG] switch_core_state_machine.c:446
(loopback/500-a) State ROUTING going to sleep
2012-11-08 21:21:08.409369 [DEBUG] switch_core_state_machine.c:398
(loopback/500-a) Running State Change CS_CONSUME_MEDIA
2012-11-08 21:21:08.409369 [DEBUG] switch_core_state_machine.c:465
(loopback/500-a) State CONSUME_MEDIA
2012-11-08 21:21:08.409369 [DEBUG] mod_loopback.c:561 CHANNEL CONSUME_MEDIA
2012-11-08 21:21:08.409369 [DEBUG] switch_core_state_machine.c:465
(loopback/500-a) State CONSUME_MEDIA going to sleep
2012-11-08 21:21:08.409369 [DEBUG] switch_core_state_machine.c:398
(loopback/500-b) Running State Change CS_INIT
2012-11-08 21:21:08.409369 [DEBUG] switch_core_state_machine.c:437
(loopback/500-b) State INIT
2012-11-08 21:21:08.409369 [DEBUG] mod_loopback.c:324 (loopback/500-b) State
Change CS_INIT -> CS_ROUTING
2012-11-08 21:21:08.409369 [DEBUG] switch_core_session.c:1210 Send signal
loopback/500-b [BREAK]
2012-11-08 21:21:08.409369 [DEBUG] mod_loopback.c:501 loopback/500-b CHANNEL
KILL
2012-11-08 21:21:08.409369 [DEBUG] switch_core_state_machine.c:437
(loopback/500-b) State INIT going to sleep
2012-11-08 21:21:08.409369 [DEBUG] switch_core_state_machine.c:398
(loopback/500-b) Running State Change CS_ROUTING
2012-11-08 21:21:08.409369 [DEBUG] switch_channel.c:1964 (loopback/500-b)
Callstate Change DOWN -> RINGING
2012-11-08 21:21:08.409369 [DEBUG] switch_core_state_machine.c:446
(loopback/500-b) State ROUTING
2012-11-08 21:21:08.409369 [DEBUG] mod_loopback.c:356 loopback/500-b CHANNEL
ROUTING
2012-11-08 21:21:08.409369 [DEBUG] switch_core_state_machine.c:117
loopback/500-b Standard ROUTING
2012-11-08 21:21:08.409369 [INFO] mod_dialplan_xml.c:485 Processing
<0000000000>->500 in context default
Dialplan: loopback/500-b parsing [default->unloop] continue=false
Dialplan: loopback/500-b Regex (PASS) [unloop] ${unroll_loops}(true) =~
/^true$/ break=on-false
Dialplan: loopback/500-b Regex (FAIL) [unloop] ${sip_looped_call}() =~
/^true$/ break=on-false
Dialplan: loopback/500-b parsing [default->tod_example] continue=true
Dialplan: loopback/500-b Date/TimeMatch (FAIL) [tod_example] break=on-false
Dialplan: loopback/500-b parsing [default->holiday_example] continue=true
Dialplan: loopback/500-b Date/TimeMatch (FAIL) [holiday_example]
break=on-false
Dialplan: loopback/500-b parsing [default->global-intercept] continue=false
Dialplan: loopback/500-b Regex (FAIL) [global-intercept]
destination_number(500) =~ /^886$/ break=on-false
Dialplan: loopback/500-b parsing [default->group-intercept] continue=false
Dialplan: loopback/500-b Regex (FAIL) [group-intercept]
destination_number(500) =~ /^\*8$/ break=on-false
Dialplan: loopback/500-b parsing [default->intercept-ext] continue=false
Dialplan: loopback/500-b Regex (FAIL) [intercept-ext]
destination_number(500) =~ /^\*\*(\d+)$/ break=on-false
Dialplan: loopback/500-b parsing [default->redial] continue=false
Dialplan: loopback/500-b Regex (FAIL) [redial] destination_number(500) =~
/^(redial|870)$/ break=on-false
Dialplan: loopback/500-b parsing [default->global] continue=true
Dialplan: loopback/500-b Regex (FAIL) [global] ${call_debug}(false) =~
/^true$/ break=never
Dialplan: loopback/500-b Regex (FAIL) [global] ${sip_has_crypto}() =~
/^(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)$/ break=never
Dialplan: loopback/500-b Absolute Condition [global]
Dialplan: loopback/500-b Action
hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid})
Dialplan: loopback/500-b Action
hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
Dialplan: loopback/500-b Action
hash(insert/${domain_name}-last_dial/global/${uuid})
Dialplan: loopback/500-b Action export(RFC2822_DATE=${strftime(%a, %d %b %Y
%T %z)})
Dialplan: loopback/500-b parsing [default->snom-demo-2] continue=false
Dialplan: loopback/500-b Regex (FAIL) [snom-demo-2] destination_number(500)
=~ /^9001$/ break=on-false
Dialplan: loopback/500-b parsing [default->snom-demo-1] continue=false
Dialplan: loopback/500-b Regex (FAIL) [snom-demo-1] destination_number(500)
=~ /^9000$/ break=on-false
Dialplan: loopback/500-b parsing [default->eavesdrop] continue=false
Dialplan: loopback/500-b Regex (FAIL) [eavesdrop] destination_number(500) =~
/^88(\d{4})$|^\*0(.*)$/ break=on-false
Dialplan: loopback/500-b parsing [default->eavesdrop] continue=false
Dialplan: loopback/500-b Regex (FAIL) [eavesdrop] destination_number(500) =~
/^779$/ break=on-false
Dialplan: loopback/500-b parsing [default->call_return] continue=false
Dialplan: loopback/500-b Regex (FAIL) [call_return] destination_number(500)
=~ /^\*69$|^869$|^lcr$/ break=on-false
Dialplan: loopback/500-b parsing [default->del-group] continue=false
Dialplan: loopback/500-b Regex (FAIL) [del-group] destination_number(500) =~
/^80(\d{2})$/ break=on-false
Dialplan: loopback/500-b parsing [default->add-group] continue=false
Dialplan: loopback/500-b Regex (FAIL) [add-group] destination_number(500) =~
/^81(\d{2})$/ break=on-false
Dialplan: loopback/500-b parsing [default->call-group-simo] continue=false
Dialplan: loopback/500-b Regex (FAIL) [call-group-simo]
destination_number(500) =~ /^82(\d{2})$/ break=on-false
Dialplan: loopback/500-b parsing [default->call-group-order] continue=false
Dialplan: loopback/500-b Regex (FAIL) [call-group-order]
destination_number(500) =~ /^83(\d{2})$/ break=on-false
Dialplan: loopback/500-b parsing [default->extension-intercom]
continue=false
Dialplan: loopback/500-b Regex (FAIL) [extension-intercom]
destination_number(500) =~ /^8(10[01][0-9])$/ break=on-false
Dialplan: loopback/500-b parsing [default->Local_Extension] continue=false
Dialplan: loopback/500-b Regex (FAIL) [Local_Extension]
destination_number(500) =~ /^(10[01][0-9])$/ break=on-false
Dialplan: loopback/500-b parsing [default->Local_Extension_Skinny]
continue=false
Dialplan: loopback/500-b Regex (FAIL) [Local_Extension_Skinny]
destination_number(500) =~ /^(11[01][0-9])$/ break=on-false
Dialplan: loopback/500-b parsing [default->group_dial_sales] continue=false
Dialplan: loopback/500-b Regex (FAIL) [group_dial_sales]
destination_number(500) =~ /^2000$/ break=on-false
Dialplan: loopback/500-b parsing [default->group_dial_support]
continue=false
Dialplan: loopback/500-b Regex (FAIL) [group_dial_support]
destination_number(500) =~ /^2001$/ break=on-false
Dialplan: loopback/500-b parsing [default->group_dial_billing]
continue=false
Dialplan: loopback/500-b Regex (FAIL) [group_dial_billing]
destination_number(500) =~ /^2002$/ break=on-false
Dialplan: loopback/500-b parsing [default->operator] continue=false
Dialplan: loopback/500-b Regex (FAIL) [operator] destination_number(500) =~
/^(operator|0)$/ break=on-false
Dialplan: loopback/500-b parsing [default->vmain] continue=false
Dialplan: loopback/500-b Regex (FAIL) [vmain] destination_number(500) =~
/^vmain$|^4000$|^\*98$/ break=on-false
Dialplan: loopback/500-b parsing [default->sip_uri] continue=false
Dialplan: loopback/500-b Regex (FAIL) [sip_uri] destination_number(500) =~
/^sip:(.*)$/ break=on-false
Dialplan: loopback/500-b parsing [default->nb_conferences] continue=false
Dialplan: loopback/500-b Regex (FAIL) [nb_conferences]
destination_number(500) =~ /^(30\d{2})$/ break=on-false
Dialplan: loopback/500-b parsing [default->wb_conferences] continue=false
Dialplan: loopback/500-b Regex (FAIL) [wb_conferences]
destination_number(500) =~ /^(31\d{2})$/ break=on-false
Dialplan: loopback/500-b parsing [default->uwb_conferences] continue=false
Dialplan: loopback/500-b Regex (FAIL) [uwb_conferences]
destination_number(500) =~ /^(32\d{2})$/ break=on-false
Dialplan: loopback/500-b parsing [default->cdquality_conferences]
continue=false
Dialplan: loopback/500-b Regex (FAIL) [cdquality_conferences]
destination_number(500) =~ /^(33\d{2})$/ break=on-false
Dialplan: loopback/500-b parsing [default->freeswitch_public_conf_via_sip]
continue=false
Dialplan: loopback/500-b Regex (FAIL) [freeswitch_public_conf_via_sip]
destination_number(500) =~ /^9(888|8888|1616|3232)$/ break=on-false
Dialplan: loopback/500-b parsing [default->mad_boss_intercom] continue=false
Dialplan: loopback/500-b Regex (FAIL) [mad_boss_intercom]
destination_number(500) =~ /^0911$/ break=on-false
Dialplan: loopback/500-b parsing [default->mad_boss_intercom] continue=false
Dialplan: loopback/500-b Regex (FAIL) [mad_boss_intercom]
destination_number(500) =~ /^0912$/ break=on-false
Dialplan: loopback/500-b parsing [default->mad_boss] continue=false
Dialplan: loopback/500-b Regex (FAIL) [mad_boss] destination_number(500) =~
/^0913$/ break=on-false
Dialplan: loopback/500-b parsing [default->ivr_demo] continue=false
Dialplan: loopback/500-b Regex (FAIL) [ivr_demo] destination_number(500) =~
/^5000$/ break=on-false
Dialplan: loopback/500-b parsing [default->dynamic_conference]
continue=false
Dialplan: loopback/500-b Regex (FAIL) [dynamic_conference]
destination_number(500) =~ /^5001$/ break=on-false
Dialplan: loopback/500-b parsing [default->rtp_multicast_page]
continue=false
Dialplan: loopback/500-b Regex (FAIL) [rtp_multicast_page]
destination_number(500) =~ /^pagegroup$|^7243$/ break=on-false
Dialplan: loopback/500-b parsing [default->park] continue=false
Dialplan: loopback/500-b Regex (FAIL) [park] destination_number(500) =~
/^5900$/ break=on-false
Dialplan: loopback/500-b parsing [default->unpark] continue=false
Dialplan: loopback/500-b Regex (FAIL) [unpark] destination_number(500) =~
/^5901$/ break=on-false
Dialplan: loopback/500-b parsing [default->valet_park] continue=false
Dialplan: loopback/500-b Regex (FAIL) [valet_park] destination_number(500)
=~ /^(6000)$/ break=on-false
Dialplan: loopback/500-b parsing [default->valet_park] continue=false
Dialplan: loopback/500-b Regex (FAIL) [valet_park] destination_number(500)
=~ /^(60\d[1-9])$/ break=on-false
Dialplan: loopback/500-b parsing [default->park] continue=false
Dialplan: loopback/500-b Regex (FAIL) [park] source(mod_loopback) =~
/mod_sofia/ break=on-false
Dialplan: loopback/500-b parsing [default->unpark] continue=false
Dialplan: loopback/500-b Regex (FAIL) [unpark] source(mod_loopback) =~
/mod_sofia/ break=on-false
Dialplan: loopback/500-b parsing [default->park] continue=false
Dialplan: loopback/500-b Regex (FAIL) [park] source(mod_loopback) =~
/mod_sofia/ break=on-false
Dialplan: loopback/500-b parsing [default->unpark] continue=false
Dialplan: loopback/500-b Regex (FAIL) [unpark] source(mod_loopback) =~
/mod_sofia/ break=on-false
Dialplan: loopback/500-b parsing [default->wait] continue=false
Dialplan: loopback/500-b Regex (FAIL) [wait] destination_number(500) =~
/^wait$/ break=on-false
Dialplan: loopback/500-b parsing [default->fax_receive] continue=false
Dialplan: loopback/500-b Regex (FAIL) [fax_receive] destination_number(500)
=~ /^9178$/ break=on-false
Dialplan: loopback/500-b parsing [default->fax_transmit] continue=false
Dialplan: loopback/500-b Regex (FAIL) [fax_transmit] destination_number(500)
=~ /^9179$/ break=on-false
Dialplan: loopback/500-b parsing [default->ringback_180] continue=false
Dialplan: loopback/500-b Regex (FAIL) [ringback_180] destination_number(500)
=~ /^9180$/ break=on-false
Dialplan: loopback/500-b parsing [default->ringback_183_uk_ring]
continue=false
Dialplan: loopback/500-b Regex (FAIL) [ringback_183_uk_ring]
destination_number(500) =~ /^9181$/ break=on-false
Dialplan: loopback/500-b parsing [default->ringback_183_music_ring]
continue=false
Dialplan: loopback/500-b Regex (FAIL) [ringback_183_music_ring]
destination_number(500) =~ /^9182$/ break=on-false
Dialplan: loopback/500-b parsing [default->ringback_post_answer_uk_ring]
continue=false
Dialplan: loopback/500-b Regex (FAIL) [ringback_post_answer_uk_ring]
destination_number(500) =~ /^9183$/ break=on-false
Dialplan: loopback/500-b parsing [default->ringback_post_answer_music]
continue=false
Dialplan: loopback/500-b Regex (FAIL) [ringback_post_answer_music]
destination_number(500) =~ /^9184$/ break=on-false
Dialplan: loopback/500-b parsing [default->ClueCon] continue=false
Dialplan: loopback/500-b Regex (FAIL) [ClueCon] destination_number(500) =~
/^9191$/ break=on-false
Dialplan: loopback/500-b parsing [default->show_info] continue=false
Dialplan: loopback/500-b Regex (FAIL) [show_info] destination_number(500) =~
/^9192$/ break=on-false
Dialplan: loopback/500-b parsing [default->video_record] continue=false
Dialplan: loopback/500-b Regex (FAIL) [video_record] destination_number(500)
=~ /^9193$/ break=on-false
Dialplan: loopback/500-b parsing [default->video_playback] continue=false
Dialplan: loopback/500-b Regex (FAIL) [video_playback]
destination_number(500) =~ /^9194$/ break=on-false
Dialplan: loopback/500-b parsing [default->delay_echo] continue=false
Dialplan: loopback/500-b Regex (FAIL) [delay_echo] destination_number(500)
=~ /^9195$/ break=on-false
Dialplan: loopback/500-b parsing [default->echo] continue=false
Dialplan: loopback/500-b Regex (FAIL) [echo] destination_number(500) =~
/^9196$/ break=on-false
Dialplan: loopback/500-b parsing [default->milliwatt] continue=false
Dialplan: loopback/500-b Regex (FAIL) [milliwatt] destination_number(500) =~
/^9197$/ break=on-false
Dialplan: loopback/500-b parsing [default->tone_stream] continue=false
Dialplan: loopback/500-b Regex (FAIL) [tone_stream] destination_number(500)
=~ /^9198$/ break=on-false
Dialplan: loopback/500-b parsing [default->zrtp_enrollement] continue=false
Dialplan: loopback/500-b Regex (FAIL) [zrtp_enrollement]
destination_number(500) =~ /^9787$/ break=on-false
Dialplan: loopback/500-b parsing [default->hold_music] continue=false
Dialplan: loopback/500-b Regex (FAIL) [hold_music] destination_number(500)
=~ /^9664$/ break=on-false
Dialplan: loopback/500-b parsing [default->laugh break] continue=false
Dialplan: loopback/500-b Regex (FAIL) [laugh break] destination_number(500)
=~ /^9386$/ break=on-false
Dialplan: loopback/500-b parsing [default->5555555] continue=false
Dialplan: loopback/500-b Regex (FAIL) [5555555] destination_number(500) =~
/^(1000)$/ break=on-false
Dialplan: loopback/500-b parsing [default->fax] continue=false
Dialplan: loopback/500-b Absolute Condition [fax]
Dialplan: loopback/500-b Action set(fax_enable_t38=true)
Dialplan: loopback/500-b Action set(execute_on_answer=t38_gateway self)
Dialplan: loopback/500-b Action set(proxy_media=true)
Dialplan: loopback/500-b Action bridge(user/500@192.168.13.18)
2012-11-08 21:21:08.409369 [DEBUG] switch_core_state_machine.c:167
(loopback/500-b) State Change CS_ROUTING -> CS_EXECUTE
2012-11-08 21:21:08.409369 [DEBUG] switch_core_session.c:1210 Send signal
loopback/500-b [BREAK]
2012-11-08 21:21:08.409369 [DEBUG] mod_loopback.c:501 loopback/500-b CHANNEL
KILL
2012-11-08 21:21:08.409369 [DEBUG] switch_core_state_machine.c:446
(loopback/500-b) State ROUTING going to sleep
2012-11-08 21:21:08.409369 [DEBUG] switch_core_state_machine.c:398
(loopback/500-b) Running State Change CS_EXECUTE
2012-11-08 21:21:08.409369 [DEBUG] switch_core_state_machine.c:453
(loopback/500-b) State EXECUTE
2012-11-08 21:21:08.409369 [DEBUG] mod_loopback.c:395 loopback/500-b CHANNEL
EXECUTE
2012-11-08 21:21:08.409369 [DEBUG] switch_core_state_machine.c:209
loopback/500-b Standard EXECUTE
EXECUTE loopback/500-b
hash(insert/192.168.13.18-spymap/0000000000/d3de53aa-7a3e-483b-bd3f-434eba87815b)
EXECUTE loopback/500-b hash(insert/192.168.13.18-last_dial/0000000000/500)
EXECUTE loopback/500-b
hash(insert/192.168.13.18-last_dial/global/d3de53aa-7a3e-483b-bd3f-434eba87815b)
EXECUTE loopback/500-b export(RFC2822_DATE=Thu, 08 Nov 2012 21:21:08 +0400)
2012-11-08 21:21:08.409369 [DEBUG] switch_channel.c:1118 EXPORT
(export_vars) [RFC2822_DATE]=[Thu, 08 Nov 2012 21:21:08 +0400]
EXECUTE loopback/500-b set(fax_enable_t38=true)
2012-11-08 21:21:08.409369 [DEBUG] mod_dptools.c:1319 loopback/500-b SET
[fax_enable_t38]=[true]
EXECUTE loopback/500-b set(execute_on_answer=t38_gateway self)
2012-11-08 21:21:08.409369 [DEBUG] mod_dptools.c:1319 loopback/500-b SET
[execute_on_answer]=[t38_gateway self]
EXECUTE loopback/500-b set(proxy_media=true)
2012-11-08 21:21:08.409369 [DEBUG] mod_dptools.c:1319 loopback/500-b SET
[proxy_media]=[true]
EXECUTE loopback/500-b bridge(user/500@192.168.13.18)
2012-11-08 21:21:08.409369 [DEBUG] switch_channel.c:1072 loopback/500-b
EXPORTING[export_vars] [RFC2822_DATE]=[Thu, 08 Nov 2012 21:21:08 +0400] to
event
2012-11-08 21:21:08.409369 [DEBUG] switch_ivr_originate.c:2005 Parsing
global variables
2012-11-08 21:21:08.409369 [DEBUG] switch_channel.c:1072 loopback/500-b
EXPORTING[export_vars] [RFC2822_DATE]=[Thu, 08 Nov 2012 21:21:08 +0400] to
event
2012-11-08 21:21:08.409369 [DEBUG] switch_ivr_originate.c:2005 Parsing
global variables
2012-11-08 21:21:08.409369 [DEBUG] switch_event.c:1569 Parsing variable
[sip_invite_domain]=[192.168.13.18]
2012-11-08 21:21:08.409369 [DEBUG] switch_event.c:1569 Parsing variable
[presence_id]=[500@192.168.13.18]
2012-11-08 21:21:08.409369 [NOTICE] switch_channel.c:951 New Channel
sofia/internal/sip:500@192.168.13.233:5060
[f617d5ed-1e77-4a22-85a1-d0db3da0fc4f]
2012-11-08 21:21:08.409369 [DEBUG] mod_sofia.c:4879
(sofia/internal/sip:500@192.168.13.233:5060) State Change CS_NEW -> CS_INIT
2012-11-08 21:21:08.409369 [DEBUG] switch_core_session.c:1210 Send signal
sofia/internal/sip:500@192.168.13.233:5060 [BREAK]
2012-11-08 21:21:08.429387 [DEBUG] switch_core_state_machine.c:398
(sofia/internal/sip:500@192.168.13.233:5060) Running State Change CS_INIT
2012-11-08 21:21:08.429387 [DEBUG] switch_core_state_machine.c:437
(sofia/internal/sip:500@192.168.13.233:5060) State INIT
2012-11-08 21:21:08.429387 [DEBUG] mod_sofia.c:86
sofia/internal/sip:500@192.168.13.233:5060 SOFIA INIT
2012-11-08 21:21:08.429387 [DEBUG] switch_core_session.c:905 Send signal
sofia/internal/sip:500@192.168.13.233:5060 [BREAK]
2012-11-08 21:21:08.429387 [DEBUG] mod_sofia.c:126
(sofia/internal/sip:500@192.168.13.233:5060) State Change CS_INIT ->
CS_ROUTING
2012-11-08 21:21:08.429387 [DEBUG] switch_core_session.c:1210 Send signal
sofia/internal/sip:500@192.168.13.233:5060 [BREAK]
2012-11-08 21:21:08.429387 [DEBUG] switch_core_state_machine.c:437
(sofia/internal/sip:500@192.168.13.233:5060) State INIT going to sleep
2012-11-08 21:21:08.429387 [DEBUG] switch_core_state_machine.c:398
(sofia/internal/sip:500@192.168.13.233:5060) Running State Change CS_ROUTING
2012-11-08 21:21:08.429387 [DEBUG] switch_channel.c:1964
(sofia/internal/sip:500@192.168.13.233:5060) Callstate Change DOWN ->
RINGING
2012-11-08 21:21:08.429387 [DEBUG] switch_core_state_machine.c:446
(sofia/internal/sip:500@192.168.13.233:5060) State ROUTING
2012-11-08 21:21:08.429387 [DEBUG] mod_sofia.c:149
sofia/internal/sip:500@192.168.13.233:5060 SOFIA ROUTING
2012-11-08 21:21:08.429387 [DEBUG] switch_ivr_originate.c:67
(sofia/internal/sip:500@192.168.13.233:5060) State Change CS_ROUTING ->
CS_CONSUME_MEDIA
2012-11-08 21:21:08.429387 [DEBUG] switch_core_session.c:1210 Send signal
sofia/internal/sip:500@192.168.13.233:5060 [BREAK]
2012-11-08 21:21:08.429387 [DEBUG] switch_core_state_machine.c:446
(sofia/internal/sip:500@192.168.13.233:5060) State ROUTING going to sleep
2012-11-08 21:21:08.429387 [DEBUG] switch_core_state_machine.c:398
(sofia/internal/sip:500@192.168.13.233:5060) Running State Change
CS_CONSUME_MEDIA
2012-11-08 21:21:08.429387 [DEBUG] switch_core_state_machine.c:465
(sofia/internal/sip:500@192.168.13.233:5060) State CONSUME_MEDIA
2012-11-08 21:21:08.429387 [DEBUG] switch_core_state_machine.c:465
(sofia/internal/sip:500@192.168.13.233:5060) State CONSUME_MEDIA going to
sleep
2012-11-08 21:21:08.429387 [DEBUG] sofia.c:6282 Channel
sofia/internal/sip:500@192.168.13.233:5060 entering state [calling][0]
2012-11-08 21:21:29.609239 [DEBUG] switch_core_session.c:905 Send signal
sofia/internal/sip:500@192.168.13.233:5060 [BREAK]
2012-11-08 21:21:29.609239 [DEBUG] switch_channel.c:2950
(sofia/internal/sip:500@192.168.13.233:5060) Callstate Change RINGING ->
HANGUP
2012-11-08 21:21:29.609239 [NOTICE] sofia.c:711 Hangup
sofia/internal/sip:500@192.168.13.233:5060 [CS_CONSUME_MEDIA]
[NORMAL_CLEARING]
2012-11-08 21:21:29.609239 [DEBUG] switch_channel.c:2973 Send signal
sofia/internal/sip:500@192.168.13.233:5060 [KILL]
2012-11-08 21:21:29.609239 [DEBUG] switch_core_session.c:1210 Send signal
sofia/internal/sip:500@192.168.13.233:5060 [BREAK]
2012-11-08 21:21:29.609239 [DEBUG] switch_core_state_machine.c:398
(sofia/internal/sip:500@192.168.13.233:5060) Running State Change CS_HANGUP
2012-11-08 21:21:29.609239 [DEBUG] switch_core_state_machine.c:638
(sofia/internal/sip:500@192.168.13.233:5060) State HANGUP
2012-11-08 21:21:29.609239 [DEBUG] mod_sofia.c:483 Channel
sofia/internal/sip:500@192.168.13.233:5060 hanging up, cause:
NORMAL_CLEARING
2012-11-08 21:21:29.609239 [DEBUG] switch_core_state_machine.c:48
sofia/internal/sip:500@192.168.13.233:5060 Standard HANGUP, cause:
NORMAL_CLEARING
2012-11-08 21:21:29.609239 [DEBUG] switch_core_state_machine.c:638
(sofia/internal/sip:500@192.168.13.233:5060) State HANGUP going to sleep
2012-11-08 21:21:29.609239 [DEBUG] switch_core_state_machine.c:429
(sofia/internal/sip:500@192.168.13.233:5060) State Change CS_HANGUP ->
CS_REPORTING
2012-11-08 21:21:29.609239 [DEBUG] switch_core_session.c:1210 Send signal
sofia/internal/sip:500@192.168.13.233:5060 [BREAK]
2012-11-08 21:21:29.609239 [DEBUG] switch_core_state_machine.c:398
(sofia/internal/sip:500@192.168.13.233:5060) Running State Change
CS_REPORTING
2012-11-08 21:21:29.609239 [DEBUG] switch_core_state_machine.c:703
(sofia/internal/sip:500@192.168.13.233:5060) State REPORTING
2012-11-08 21:21:29.609239 [DEBUG] switch_core_state_machine.c:92
sofia/internal/sip:500@192.168.13.233:5060 Standard REPORTING, cause:
NORMAL_CLEARING
2012-11-08 21:21:29.609239 [DEBUG] switch_core_state_machine.c:703
(sofia/internal/sip:500@192.168.13.233:5060) State REPORTING going to sleep
2012-11-08 21:21:29.609239 [DEBUG] switch_core_state_machine.c:423
(sofia/internal/sip:500@192.168.13.233:5060) State Change CS_REPORTING ->
CS_DESTROY
2012-11-08 21:21:29.609239 [DEBUG] switch_core_session.c:1210 Send signal
sofia/internal/sip:500@192.168.13.233:5060 [BREAK]
2012-11-08 21:21:29.609239 [DEBUG] switch_core_session.c:1415 Session 35
(sofia/internal/sip:500@192.168.13.233:5060) Locked, Waiting on external
entities
2012-11-08 21:21:29.629589 [DEBUG] switch_ivr_originate.c:3508 Originate
Resulted in Error Cause: 16 [NORMAL_CLEARING]
2012-11-08 21:21:29.629589 [NOTICE] switch_ivr_originate.c:2591 Cannot
create outgoing channel of type [user] cause: [NORMAL_CLEARING]
2012-11-08 21:21:29.629589 [NOTICE] switch_core_session.c:1433 Session 35
(sofia/internal/sip:500@192.168.13.233:5060) Ended
2012-11-08 21:21:29.629589 [NOTICE] switch_core_session.c:1437 Close Channel
sofia/internal/sip:500@192.168.13.233:5060 [CS_DESTROY]
2012-11-08 21:21:29.629589 [DEBUG] switch_ivr_originate.c:3508 Originate
Resulted in Error Cause: 16 [NORMAL_CLEARING]
2012-11-08 21:21:29.629589 [INFO] mod_dptools.c:3027 Originate Failed.
Cause: NORMAL_CLEARING
2012-11-08 21:21:29.629589 [DEBUG] switch_channel.c:2950 (loopback/500-b)
Callstate Change RINGING -> HANGUP
2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:527
(sofia/internal/sip:500@192.168.13.233:5060) Callstate Change HANGUP -> DOWN
2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:530
(sofia/internal/sip:500@192.168.13.233:5060) Running State Change CS_DESTROY
2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:540
(sofia/internal/sip:500@192.168.13.233:5060) State DESTROY
2012-11-08 21:21:29.629589 [DEBUG] mod_sofia.c:376
sofia/internal/sip:500@192.168.13.233:5060 SOFIA DESTROY
2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:99
sofia/internal/sip:500@192.168.13.233:5060 Standard DESTROY
2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:540
(sofia/internal/sip:500@192.168.13.233:5060) State DESTROY going to sleep
2012-11-08 21:21:29.629589 [NOTICE] mod_dptools.c:3147 Hangup loopback/500-b
[CS_EXECUTE] [NORMAL_CLEARING]
2012-11-08 21:21:29.629589 [DEBUG] switch_channel.c:2973 Send signal
loopback/500-b [KILL]
2012-11-08 21:21:29.629589 [DEBUG] mod_loopback.c:501 loopback/500-b CHANNEL
KILL
2012-11-08 21:21:29.629589 [DEBUG] switch_core_session.c:1210 Send signal
loopback/500-b [BREAK]
2012-11-08 21:21:29.629589 [DEBUG] mod_loopback.c:501 loopback/500-b CHANNEL
KILL
2012-11-08 21:21:29.629589 [DEBUG] switch_core_session.c:2553 loopback/500-b
skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:453
(loopback/500-b) State EXECUTE going to sleep
2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:398
(loopback/500-b) Running State Change CS_HANGUP
2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:638
(loopback/500-b) State HANGUP
2012-11-08 21:21:29.629589 [DEBUG] mod_loopback.c:453 loopback/500-b CHANNEL
HANGUP
2012-11-08 21:21:29.629589 [DEBUG] switch_channel.c:2950 (loopback/500-a)
Callstate Change RINGING -> HANGUP
2012-11-08 21:21:29.629589 [NOTICE] mod_loopback.c:464 Hangup loopback/500-a
[CS_CONSUME_MEDIA] [NORMAL_CLEARING]
2012-11-08 21:21:29.629589 [DEBUG] switch_channel.c:2973 Send signal
loopback/500-a [KILL]
2012-11-08 21:21:29.629589 [DEBUG] mod_loopback.c:501 loopback/500-a CHANNEL
KILL
2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:398
(loopback/500-a) Running State Change CS_HANGUP
2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:638
(loopback/500-a) State HANGUP
2012-11-08 21:21:29.629589 [DEBUG] mod_loopback.c:453 loopback/500-a CHANNEL
HANGUP
2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:48
loopback/500-a Standard HANGUP, cause: NORMAL_CLEARING
2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:638
(loopback/500-a) State HANGUP going to sleep
2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:429
(loopback/500-a) State Change CS_HANGUP -> CS_REPORTING
2012-11-08 21:21:29.629589 [DEBUG] switch_core_session.c:1210 Send signal
loopback/500-a [BREAK]
2012-11-08 21:21:29.629589 [DEBUG] mod_loopback.c:501 loopback/500-a CHANNEL
KILL
2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:398
(loopback/500-a) Running State Change CS_REPORTING
2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:703
(loopback/500-a) State REPORTING
2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:92
loopback/500-a Standard REPORTING, cause: NORMAL_CLEARING
2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:703
(loopback/500-a) State REPORTING going to sleep
2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:423
(loopback/500-a) State Change CS_REPORTING -> CS_DESTROY
2012-11-08 21:21:29.629589 [DEBUG] switch_core_session.c:1210 Send signal
loopback/500-a [BREAK]
2012-11-08 21:21:29.629589 [DEBUG] mod_loopback.c:501 loopback/500-a CHANNEL
KILL
2012-11-08 21:21:29.629589 [DEBUG] switch_core_session.c:1415 Session 33
(loopback/500-a) Locked, Waiting on external entities
2012-11-08 21:21:29.629589 [DEBUG] switch_core_session.c:1210 Send signal
loopback/500-a [BREAK]
2012-11-08 21:21:29.629589 [DEBUG] mod_loopback.c:501 loopback/500-a CHANNEL
KILL
2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:48
loopback/500-b Standard HANGUP, cause: NORMAL_CLEARING
2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:638
(loopback/500-b) State HANGUP going to sleep
2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:429
(loopback/500-b) State Change CS_HANGUP -> CS_REPORTING
2012-11-08 21:21:29.629589 [DEBUG] switch_core_session.c:1210 Send signal
loopback/500-b [BREAK]
2012-11-08 21:21:29.629589 [DEBUG] mod_loopback.c:501 loopback/500-b CHANNEL
KILL
2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:398
(loopback/500-b) Running State Change CS_REPORTING
2012-11-08 21:21:29.629589 [DEBUG] switch_ivr_originate.c:3508 Originate
Resulted in Error Cause: 16 [NORMAL_CLEARING]
2012-11-08 21:21:29.629589 [NOTICE] switch_core_session.c:1433 Session 33
(loopback/500-a) Ended
2012-11-08 21:21:29.629589 [NOTICE] switch_core_session.c:1437 Close Channel
loopback/500-a [CS_DESTROY]
2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:527
(loopback/500-a) Callstate Change HANGUP -> DOWN
2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:530
(loopback/500-a) Running State Change CS_DESTROY
2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:540
(loopback/500-a) State DESTROY
2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:99
loopback/500-a Standard DESTROY
2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:540
(loopback/500-a) State DESTROY going to sleep
2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:703
(loopback/500-b) State REPORTING
2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:92
loopback/500-b Standard REPORTING, cause: NORMAL_CLEARING
2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:703
(loopback/500-b) State REPORTING going to sleep
2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:423
(loopback/500-b) State Change CS_REPORTING -> CS_DESTROY
2012-11-08 21:21:29.629589 [DEBUG] switch_core_session.c:1210 Send signal
loopback/500-b [BREAK]
2012-11-08 21:21:29.629589 [DEBUG] mod_loopback.c:501 loopback/500-b CHANNEL
KILL
2012-11-08 21:21:29.629589 [DEBUG] switch_core_session.c:1415 Session 34
(loopback/500-b) Locked, Waiting on external entities
2012-11-08 21:21:29.629589 [NOTICE] switch_core_session.c:1433 Session 34
(loopback/500-b) Ended
2012-11-08 21:21:29.629589 [NOTICE] switch_core_session.c:1437 Close Channel
loopback/500-b [CS_DESTROY]
2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:527
(loopback/500-b) Callstate Change HANGUP -> DOWN
2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:530
(loopback/500-b) Running State Change CS_DESTROY
2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:540
(loopback/500-b) State DESTROY
2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:99
loopback/500-b Standard DESTROY
2012-11-08 21:21:29.629589 [DEBUG] switch_core_state_machine.c:540
(loopback/500-b) State DESTROY going to sleep

so I'm trying to send a fax to the fax 501 -> 500
log:
2012-11-08 21:18:21.109351 [NOTICE] switch_channel.c:951 New Channel
sofia/internal/501@192.168.13.18 [ce35cc96-6ce5-4cf7-a9f0-71f7d31e454d]
2012-11-08 21:18:21.109351 [DEBUG] switch_core_session.c:905 Send signal
sofia/internal/501@192.168.13.18 [BREAK]
2012-11-08 21:18:21.129757 [DEBUG] switch_core_state_machine.c:398
(sofia/internal/501@192.168.13.18) Running State Change CS_NEW
2012-11-08 21:18:21.129757 [DEBUG] switch_core_state_machine.c:416
(sofia/internal/501@192.168.13.18) State NEW
2012-11-08 21:18:21.129757 [DEBUG] switch_core_session.c:905 Send signal
sofia/internal/501@192.168.13.18 [BREAK]
2012-11-08 21:18:21.149399 [DEBUG] sofia.c:8412 IP 192.168.13.71 Rejected by
acl "domains". Falling back to Digest auth.
2012-11-08 21:18:21.149399 [DEBUG] switch_core_session.c:905 Send signal
sofia/internal/501@192.168.13.18 [BREAK]
2012-11-08 21:18:21.149399 [DEBUG] sofia.c:1728 detaching session
ce35cc96-6ce5-4cf7-a9f0-71f7d31e454d
2012-11-08 21:18:21.149399 [DEBUG] sofia.c:1820 Re-attaching to session
ce35cc96-6ce5-4cf7-a9f0-71f7d31e454d
2012-11-08 21:18:21.149399 [DEBUG] switch_core_session.c:905 Send signal
sofia/internal/501@192.168.13.18 [BREAK]
2012-11-08 21:18:21.149399 [DEBUG] switch_core_session.c:905 Send signal
sofia/internal/501@192.168.13.18 [BREAK]
2012-11-08 21:18:21.169346 [DEBUG] sofia.c:8412 IP 192.168.13.71 Rejected by
acl "domains". Falling back to Digest auth.
2012-11-08 21:18:21.169346 [DEBUG] sofia.c:6282 Channel
sofia/internal/501@192.168.13.18 entering state [received][100]
2012-11-08 21:18:21.169346 [DEBUG] sofia.c:6293 Remote SDP:
v=0
o=- 1352395099 1 IN IP4 192.168.13.71
s=VFT38M/v.25.08.2012
c=IN IP4 192.168.13.71
t=0 0
m=audio 5018 RTP/AVP 0 8 101
a=rtpmap:0 PCMU/8000/1
a=rtpmap:8 PCMA/8000/1
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16,32,36
a=maxptime:240

2012-11-08 21:18:21.169346 [DEBUG] sofia.c:6506
(sofia/internal/501@192.168.13.18) State Change CS_NEW -> CS_INIT
2012-11-08 21:18:21.169346 [DEBUG] switch_core_session.c:1210 Send signal
sofia/internal/501@192.168.13.18 [BREAK]
2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:398
(sofia/internal/501@192.168.13.18) Running State Change CS_INIT
2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:437
(sofia/internal/501@192.168.13.18) State INIT
2012-11-08 21:18:21.169346 [DEBUG] mod_sofia.c:86
sofia/internal/501@192.168.13.18 SOFIA INIT
2012-11-08 21:18:21.169346 [DEBUG] mod_sofia.c:126
(sofia/internal/501@192.168.13.18) State Change CS_INIT -> CS_ROUTING
2012-11-08 21:18:21.169346 [DEBUG] switch_core_session.c:1210 Send signal
sofia/internal/501@192.168.13.18 [BREAK]
2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:437
(sofia/internal/501@192.168.13.18) State INIT going to sleep
2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:398
(sofia/internal/501@192.168.13.18) Running State Change CS_ROUTING
2012-11-08 21:18:21.169346 [DEBUG] switch_channel.c:1964
(sofia/internal/501@192.168.13.18) Callstate Change DOWN -> RINGING
2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:446
(sofia/internal/501@192.168.13.18) State ROUTING
2012-11-08 21:18:21.169346 [DEBUG] mod_sofia.c:149
sofia/internal/501@192.168.13.18 SOFIA ROUTING
2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:117
sofia/internal/501@192.168.13.18 Standard ROUTING
2012-11-08 21:18:21.169346 [INFO] mod_dialplan_xml.c:485 Processing 501
<501>->500 in context default
Dialplan: sofia/internal/501@192.168.13.18 parsing [default->unloop]
continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (PASS) [unloop]
${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [unloop]
${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing [default->tod_example]
continue=true
Dialplan: sofia/internal/501@192.168.13.18 Date/TimeMatch (FAIL)
[tod_example] break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing
[default->holiday_example] continue=true
Dialplan: sofia/internal/501@192.168.13.18 Date/TimeMatch (FAIL)
[holiday_example] break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing
[default->global-intercept] continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [global-intercept]
destination_number(500) =~ /^886$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing
[default->group-intercept] continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [group-intercept]
destination_number(500) =~ /^\*8$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing [default->intercept-ext]
continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [intercept-ext]
destination_number(500) =~ /^\*\*(\d+)$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing [default->redial]
continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [redial]
destination_number(500) =~ /^(redial|870)$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing [default->global]
continue=true
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [global]
${call_debug}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [global]
${sip_has_crypto}() =~ /^(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)$/
break=never
Dialplan: sofia/internal/501@192.168.13.18 Absolute Condition [global]
Dialplan: sofia/internal/501@192.168.13.18 Action
hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid})
Dialplan: sofia/internal/501@192.168.13.18 Action
hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
Dialplan: sofia/internal/501@192.168.13.18 Action
hash(insert/${domain_name}-last_dial/global/${uuid})
Dialplan: sofia/internal/501@192.168.13.18 Action
export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
Dialplan: sofia/internal/501@192.168.13.18 parsing [default->snom-demo-2]
continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [snom-demo-2]
destination_number(500) =~ /^9001$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing [default->snom-demo-1]
continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [snom-demo-1]
destination_number(500) =~ /^9000$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing [default->eavesdrop]
continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [eavesdrop]
destination_number(500) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing [default->eavesdrop]
continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [eavesdrop]
destination_number(500) =~ /^779$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing [default->call_return]
continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [call_return]
destination_number(500) =~ /^\*69$|^869$|^lcr$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing [default->del-group]
continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [del-group]
destination_number(500) =~ /^80(\d{2})$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing [default->add-group]
continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [add-group]
destination_number(500) =~ /^81(\d{2})$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing
[default->call-group-simo] continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [call-group-simo]
destination_number(500) =~ /^82(\d{2})$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing
[default->call-group-order] continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [call-group-order]
destination_number(500) =~ /^83(\d{2})$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing
[default->extension-intercom] continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [extension-intercom]
destination_number(500) =~ /^8(10[01][0-9])$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing
[default->Local_Extension] continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [Local_Extension]
destination_number(500) =~ /^(10[01][0-9])$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing
[default->Local_Extension_Skinny] continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL)
[Local_Extension_Skinny] destination_number(500) =~ /^(11[01][0-9])$/
break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing
[default->group_dial_sales] continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [group_dial_sales]
destination_number(500) =~ /^2000$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing
[default->group_dial_support] continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [group_dial_support]
destination_number(500) =~ /^2001$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing
[default->group_dial_billing] continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [group_dial_billing]
destination_number(500) =~ /^2002$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing [default->operator]
continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [operator]
destination_number(500) =~ /^(operator|0)$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing [default->vmain]
continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [vmain]
destination_number(500) =~ /^vmain$|^4000$|^\*98$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing [default->sip_uri]
continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [sip_uri]
destination_number(500) =~ /^sip:(.*)$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing [default->nb_conferences]
continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [nb_conferences]
destination_number(500) =~ /^(30\d{2})$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing [default->wb_conferences]
continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [wb_conferences]
destination_number(500) =~ /^(31\d{2})$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing
[default->uwb_conferences] continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [uwb_conferences]
destination_number(500) =~ /^(32\d{2})$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing
[default->cdquality_conferences] continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL)
[cdquality_conferences] destination_number(500) =~ /^(33\d{2})$/
break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing
[default->freeswitch_public_conf_via_sip] continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL)
[freeswitch_public_conf_via_sip] destination_number(500) =~
/^9(888|8888|1616|3232)$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing
[default->mad_boss_intercom] continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [mad_boss_intercom]
destination_number(500) =~ /^0911$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing
[default->mad_boss_intercom] continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [mad_boss_intercom]
destination_number(500) =~ /^0912$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing [default->mad_boss]
continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [mad_boss]
destination_number(500) =~ /^0913$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing [default->ivr_demo]
continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [ivr_demo]
destination_number(500) =~ /^5000$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing
[default->dynamic_conference] continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [dynamic_conference]
destination_number(500) =~ /^5001$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing
[default->rtp_multicast_page] continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [rtp_multicast_page]
destination_number(500) =~ /^pagegroup$|^7243$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing [default->park]
continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [park]
destination_number(500) =~ /^5900$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing [default->unpark]
continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [unpark]
destination_number(500) =~ /^5901$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing [default->valet_park]
continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [valet_park]
destination_number(500) =~ /^(6000)$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing [default->valet_park]
continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [valet_park]
destination_number(500) =~ /^(60\d[1-9])$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing [default->park]
continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (PASS) [park]
source(mod_sofia) =~ /mod_sofia/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [park]
destination_number(500) =~ /park\+(\d+)/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing [default->unpark]
continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (PASS) [unpark]
source(mod_sofia) =~ /mod_sofia/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [unpark]
destination_number(500) =~ /^parking$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing [default->park]
continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (PASS) [park]
source(mod_sofia) =~ /mod_sofia/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [park]
destination_number(500) =~ /callpark/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing [default->unpark]
continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (PASS) [unpark]
source(mod_sofia) =~ /mod_sofia/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [unpark]
destination_number(500) =~ /pickup/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing [default->wait]
continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [wait]
destination_number(500) =~ /^wait$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing [default->fax_receive]
continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [fax_receive]
destination_number(500) =~ /^9178$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing [default->fax_transmit]
continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [fax_transmit]
destination_number(500) =~ /^9179$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing [default->ringback_180]
continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [ringback_180]
destination_number(500) =~ /^9180$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing
[default->ringback_183_uk_ring] continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL)
[ringback_183_uk_ring] destination_number(500) =~ /^9181$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing
[default->ringback_183_music_ring] continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL)
[ringback_183_music_ring] destination_number(500) =~ /^9182$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing
[default->ringback_post_answer_uk_ring] continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL)
[ringback_post_answer_uk_ring] destination_number(500) =~ /^9183$/
break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing
[default->ringback_post_answer_music] continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL)
[ringback_post_answer_music] destination_number(500) =~ /^9184$/
break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing [default->ClueCon]
continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [ClueCon]
destination_number(500) =~ /^9191$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing [default->show_info]
continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [show_info]
destination_number(500) =~ /^9192$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing [default->video_record]
continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [video_record]
destination_number(500) =~ /^9193$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing [default->video_playback]
continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [video_playback]
destination_number(500) =~ /^9194$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing [default->delay_echo]
continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [delay_echo]
destination_number(500) =~ /^9195$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing [default->echo]
continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [echo]
destination_number(500) =~ /^9196$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing [default->milliwatt]
continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [milliwatt]
destination_number(500) =~ /^9197$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing [default->tone_stream]
continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [tone_stream]
destination_number(500) =~ /^9198$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing
[default->zrtp_enrollement] continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [zrtp_enrollement]
destination_number(500) =~ /^9787$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing [default->hold_music]
continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [hold_music]
destination_number(500) =~ /^9664$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing [default->laugh break]
continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [laugh break]
destination_number(500) =~ /^9386$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing [default->5555555]
continue=false
Dialplan: sofia/internal/501@192.168.13.18 Regex (FAIL) [5555555]
destination_number(500) =~ /^(1000)$/ break=on-false
Dialplan: sofia/internal/501@192.168.13.18 parsing [default->fax]
continue=false
Dialplan: sofia/internal/501@192.168.13.18 Absolute Condition [fax]
Dialplan: sofia/internal/501@192.168.13.18 Action set(fax_enable_t38=true)
Dialplan: sofia/internal/501@192.168.13.18 Action
set(execute_on_answer=t38_gateway self)
Dialplan: sofia/internal/501@192.168.13.18 Action set(proxy_media=true)
Dialplan: sofia/internal/501@192.168.13.18 Action
bridge(user/500@192.168.13.18)
2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:167
(sofia/internal/501@192.168.13.18) State Change CS_ROUTING -> CS_EXECUTE
2012-11-08 21:18:21.169346 [DEBUG] switch_core_session.c:1210 Send signal
sofia/internal/501@192.168.13.18 [BREAK]
2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:446
(sofia/internal/501@192.168.13.18) State ROUTING going to sleep
2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:398
(sofia/internal/501@192.168.13.18) Running State Change CS_EXECUTE
2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:453
(sofia/internal/501@192.168.13.18) State EXECUTE
2012-11-08 21:18:21.169346 [DEBUG] mod_sofia.c:242
sofia/internal/501@192.168.13.18 SOFIA EXECUTE
2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:209
sofia/internal/501@192.168.13.18 Standard EXECUTE
EXECUTE sofia/internal/501@192.168.13.18
hash(insert/192.168.13.18-spymap/501/ce35cc96-6ce5-4cf7-a9f0-71f7d31e454d)
EXECUTE sofia/internal/501@192.168.13.18
hash(insert/192.168.13.18-last_dial/501/500)
EXECUTE sofia/internal/501@192.168.13.18
hash(insert/192.168.13.18-last_dial/global/ce35cc96-6ce5-4cf7-a9f0-71f7d31e454d)
EXECUTE sofia/internal/501@192.168.13.18 export(RFC2822_DATE=Thu, 08 Nov
2012 21:18:21 +0400)
2012-11-08 21:18:21.169346 [DEBUG] switch_channel.c:1118 EXPORT
(export_vars) [RFC2822_DATE]=[Thu, 08 Nov 2012 21:18:21 +0400]
EXECUTE sofia/internal/501@192.168.13.18 set(fax_enable_t38=true)
2012-11-08 21:18:21.169346 [DEBUG] mod_dptools.c:1319
sofia/internal/501@192.168.13.18 SET [fax_enable_t38]=[true]
EXECUTE sofia/internal/501@192.168.13.18 set(execute_on_answer=t38_gateway
self)
2012-11-08 21:18:21.169346 [DEBUG] mod_dptools.c:1319
sofia/internal/501@192.168.13.18 SET [execute_on_answer]=[t38_gateway self]
EXECUTE sofia/internal/501@192.168.13.18 set(proxy_media=true)
2012-11-08 21:18:21.169346 [DEBUG] mod_dptools.c:1319
sofia/internal/501@192.168.13.18 SET [proxy_media]=[true]
EXECUTE sofia/internal/501@192.168.13.18 bridge(user/500@192.168.13.18)
2012-11-08 21:18:21.169346 [DEBUG] switch_channel.c:1072
sofia/internal/501@192.168.13.18 EXPORTING[export_vars] [RFC2822_DATE]=[Thu,
08 Nov 2012 21:18:21 +0400] to event
2012-11-08 21:18:21.169346 [DEBUG] switch_ivr_originate.c:2005 Parsing
global variables
2012-11-08 21:18:21.169346 [DEBUG] switch_channel.c:1072
sofia/internal/501@192.168.13.18 EXPORTING[export_vars] [RFC2822_DATE]=[Thu,
08 Nov 2012 21:18:21 +0400] to event
2012-11-08 21:18:21.169346 [DEBUG] switch_ivr_originate.c:2005 Parsing
global variables
2012-11-08 21:18:21.169346 [DEBUG] switch_event.c:1569 Parsing variable
[sip_invite_domain]=[192.168.13.18]
2012-11-08 21:18:21.169346 [DEBUG] switch_event.c:1569 Parsing variable
[presence_id]=[500@192.168.13.18]
2012-11-08 21:18:21.169346 [NOTICE] switch_channel.c:951 New Channel
sofia/internal/sip:500@192.168.13.233:5060
[a318696b-d309-4724-abc6-1f0aca4f0dd3]
2012-11-08 21:18:21.169346 [DEBUG] mod_sofia.c:4879
(sofia/internal/sip:500@192.168.13.233:5060) State Change CS_NEW -> CS_INIT
2012-11-08 21:18:21.169346 [DEBUG] switch_core_session.c:1210 Send signal
sofia/internal/sip:500@192.168.13.233:5060 [BREAK]
2012-11-08 21:18:21.169346 [DEBUG] mod_sofia.c:4954 [zrtp_passthru] Setting
a-leg inherit_codec=true
2012-11-08 21:18:21.169346 [DEBUG] mod_sofia.c:4957 [zrtp_passthru] Setting
b-leg absolute_codec_string='PCMU@8000h@20i@64000b,PCMA@8000h@20i@64000b'
2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:398
(sofia/internal/sip:500@192.168.13.233:5060) Running State Change CS_INIT
2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:437
(sofia/internal/sip:500@192.168.13.233:5060) State INIT
2012-11-08 21:18:21.169346 [DEBUG] mod_sofia.c:86
sofia/internal/sip:500@192.168.13.233:5060 SOFIA INIT
2012-11-08 21:18:21.169346 [DEBUG] sofia_glue.c:1920
sofia/internal/sip:500@192.168.13.233:5060 Patched SDP
---
v=0
o=- 1352395099 1 IN IP4 192.168.13.71
s=VFT38M/v.25.08.2012
c=IN IP4 192.168.13.71
t=0 0
m=audio 5018 RTP/AVP 0 8 101
a=rtpmap:0 PCMU/8000/1
a=rtpmap:8 PCMA/8000/1
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16,32,36
a=maxptime:240

+++
v=0
o=FreeSWITCH 3287184146 3287184147 IN IP4 192.168.13.18
s=FreeSWITCH
c=IN IP4 192.168.13.18
t=0 0
m=audio 16966 RTP/AVP 0 8 101
a=rtpmap:0 PCMU/8000/1
a=rtpmap:8 PCMA/8000/1
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16,32,36
a=maxptime:240

2012-11-08 21:18:21.169346 [DEBUG] sofia_glue.c:2637 Local SDP:
v=0
o=FreeSWITCH 3287184146 3287184147 IN IP4 192.168.13.18
s=FreeSWITCH
c=IN IP4 192.168.13.18
t=0 0
m=audio 16966 RTP/AVP 0 8 101
a=rtpmap:0 PCMU/8000/1
a=rtpmap:8 PCMA/8000/1
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16,32,36
a=maxptime:240

2012-11-08 21:18:21.169346 [DEBUG] switch_core_session.c:905 Send signal
sofia/internal/sip:500@192.168.13.233:5060 [BREAK]
2012-11-08 21:18:21.169346 [DEBUG] mod_sofia.c:126
(sofia/internal/sip:500@192.168.13.233:5060) State Change CS_INIT ->
CS_ROUTING
2012-11-08 21:18:21.169346 [DEBUG] switch_core_session.c:1210 Send signal
sofia/internal/sip:500@192.168.13.233:5060 [BREAK]
2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:437
(sofia/internal/sip:500@192.168.13.233:5060) State INIT going to sleep
2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:398
(sofia/internal/sip:500@192.168.13.233:5060) Running State Change CS_ROUTING
2012-11-08 21:18:21.169346 [DEBUG] switch_channel.c:1964
(sofia/internal/sip:500@192.168.13.233:5060) Callstate Change DOWN ->
RINGING
2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:446
(sofia/internal/sip:500@192.168.13.233:5060) State ROUTING
2012-11-08 21:18:21.169346 [DEBUG] mod_sofia.c:149
sofia/internal/sip:500@192.168.13.233:5060 SOFIA ROUTING
2012-11-08 21:18:21.169346 [DEBUG] switch_ivr_originate.c:67
(sofia/internal/sip:500@192.168.13.233:5060) State Change CS_ROUTING ->
CS_CONSUME_MEDIA
2012-11-08 21:18:21.169346 [DEBUG] switch_core_session.c:1210 Send signal
sofia/internal/sip:500@192.168.13.233:5060 [BREAK]
2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:446
(sofia/internal/sip:500@192.168.13.233:5060) State ROUTING going to sleep
2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:398
(sofia/internal/sip:500@192.168.13.233:5060) Running State Change
CS_CONSUME_MEDIA
2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:465
(sofia/internal/sip:500@192.168.13.233:5060) State CONSUME_MEDIA
2012-11-08 21:18:21.169346 [DEBUG] switch_core_state_machine.c:465
(sofia/internal/sip:500@192.168.13.233:5060) State CONSUME_MEDIA going to
sleep
2012-11-08 21:18:21.169346 [DEBUG] sofia.c:6282 Channel
sofia/internal/sip:500@192.168.13.233:5060 entering state [calling][0]
2012-11-08 21:18:53.169624 [DEBUG] switch_core_session.c:905 Send signal
sofia/internal/sip:500@192.168.13.233:5060 [BREAK]
2012-11-08 21:18:53.169624 [DEBUG] switch_core_session.c:905 Send signal
sofia/internal/sip:500@192.168.13.233:5060 [BREAK]
2012-11-08 21:18:53.169624 [DEBUG] sofia.c:6282 Channel
sofia/internal/sip:500@192.168.13.233:5060 entering state [terminated][408]
2012-11-08 21:18:53.169624 [DEBUG] switch_channel.c:2950
(sofia/internal/sip:500@192.168.13.233:5060) Callstate Change RINGING ->
HANGUP
2012-11-08 21:18:53.169624 [NOTICE] sofia.c:7082 Hangup
sofia/internal/sip:500@192.168.13.233:5060 [CS_CONSUME_MEDIA]
[RECOVERY_ON_TIMER_EXPIRE]
2012-11-08 21:18:53.169624 [DEBUG] switch_channel.c:2973 Send signal
sofia/internal/sip:500@192.168.13.233:5060 [KILL]
2012-11-08 21:18:53.169624 [DEBUG] switch_core_session.c:1210 Send signal
sofia/internal/sip:500@192.168.13.233:5060 [BREAK]
2012-11-08 21:18:53.169624 [DEBUG] switch_core_state_machine.c:398
(sofia/internal/sip:500@192.168.13.233:5060) Running State Change CS_HANGUP
2012-11-08 21:18:53.169624 [DEBUG] switch_core_state_machine.c:638
(sofia/internal/sip:500@192.168.13.233:5060) State HANGUP
2012-11-08 21:18:53.169624 [DEBUG] mod_sofia.c:483 Channel
sofia/internal/sip:500@192.168.13.233:5060 hanging up, cause:
RECOVERY_ON_TIMER_EXPIRE
2012-11-08 21:18:53.169624 [DEBUG] switch_core_state_machine.c:48
sofia/internal/sip:500@192.168.13.233:5060 Standard HANGUP, cause:
RECOVERY_ON_TIMER_EXPIRE
2012-11-08 21:18:53.169624 [DEBUG] switch_core_state_machine.c:638
(sofia/internal/sip:500@192.168.13.233:5060) State HANGUP going to sleep
2012-11-08 21:18:53.169624 [DEBUG] switch_core_state_machine.c:429
(sofia/internal/sip:500@192.168.13.233:5060) State Change CS_HANGUP ->
CS_REPORTING
2012-11-08 21:18:53.169624 [DEBUG] switch_core_session.c:1210 Send signal
sofia/internal/sip:500@192.168.13.233:5060 [BREAK]
2012-11-08 21:18:53.169624 [DEBUG] switch_core_state_machine.c:398
(sofia/internal/sip:500@192.168.13.233:5060) Running State Change
CS_REPORTING
2012-11-08 21:18:53.169624 [DEBUG] switch_core_state_machine.c:703
(sofia/internal/sip:500@192.168.13.233:5060) State REPORTING
2012-11-08 21:18:53.169624 [DEBUG] switch_core_state_machine.c:92
sofia/internal/sip:500@192.168.13.233:5060 Standard REPORTING, cause:
RECOVERY_ON_TIMER_EXPIRE
2012-11-08 21:18:53.169624 [DEBUG] switch_core_state_machine.c:703
(sofia/internal/sip:500@192.168.13.233:5060) State REPORTING going to sleep
2012-11-08 21:18:53.169624 [DEBUG] switch_core_state_machine.c:423
(sofia/internal/sip:500@192.168.13.233:5060) State Change CS_REPORTING ->
CS_DESTROY
2012-11-08 21:18:53.169624 [DEBUG] switch_core_session.c:1210 Send signal
sofia/internal/sip:500@192.168.13.233:5060 [BREAK]
2012-11-08 21:18:53.169624 [DEBUG] switch_core_session.c:1415 Session 30
(sofia/internal/sip:500@192.168.13.233:5060) Locked, Waiting on external
entities
2012-11-08 21:18:53.190125 [DEBUG] switch_ivr_originate.c:3508 Originate
Resulted in Error Cause: 102 [RECOVERY_ON_TIMER_EXPIRE]
2012-11-08 21:18:53.190125 [NOTICE] switch_ivr_originate.c:2591 Cannot
create outgoing channel of type [user] cause: [RECOVERY_ON_TIMER_EXPIRE]
2012-11-08 21:18:53.190125 [NOTICE] switch_core_session.c:1433 Session 30
(sofia/internal/sip:500@192.168.13.233:5060) Ended
2012-11-08 21:18:53.190125 [NOTICE] switch_core_session.c:1437 Close Channel
sofia/internal/sip:500@192.168.13.233:5060 [CS_DESTROY]
2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:527
(sofia/internal/sip:500@192.168.13.233:5060) Callstate Change HANGUP -> DOWN
2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:530
(sofia/internal/sip:500@192.168.13.233:5060) Running State Change CS_DESTROY
2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:540
(sofia/internal/sip:500@192.168.13.233:5060) State DESTROY
2012-11-08 21:18:53.190125 [DEBUG] mod_sofia.c:376
sofia/internal/sip:500@192.168.13.233:5060 SOFIA DESTROY
2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:99
sofia/internal/sip:500@192.168.13.233:5060 Standard DESTROY
2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:540
(sofia/internal/sip:500@192.168.13.233:5060) State DESTROY going to sleep
2012-11-08 21:18:53.190125 [DEBUG] switch_ivr_originate.c:3508 Originate
Resulted in Error Cause: 102 [RECOVERY_ON_TIMER_EXPIRE]
2012-11-08 21:18:53.190125 [INFO] mod_dptools.c:3027 Originate Failed.
Cause: RECOVERY_ON_TIMER_EXPIRE
2012-11-08 21:18:53.190125 [DEBUG] switch_channel.c:2950
(sofia/internal/501@192.168.13.18) Callstate Change RINGING -> HANGUP
2012-11-08 21:18:53.190125 [NOTICE] mod_dptools.c:3147 Hangup
sofia/internal/501@192.168.13.18 [CS_EXECUTE] [RECOVERY_ON_TIMER_EXPIRE]
2012-11-08 21:18:53.190125 [DEBUG] switch_channel.c:2973 Send signal
sofia/internal/501@192.168.13.18 [KILL]
2012-11-08 21:18:53.190125 [DEBUG] switch_core_session.c:1210 Send signal
sofia/internal/501@192.168.13.18 [BREAK]
2012-11-08 21:18:53.190125 [DEBUG] switch_core_session.c:2553
sofia/internal/501@192.168.13.18 skip receive message
[APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:453
(sofia/internal/501@192.168.13.18) State EXECUTE going to sleep
2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:398
(sofia/internal/501@192.168.13.18) Running State Change CS_HANGUP
2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:638
(sofia/internal/501@192.168.13.18) State HANGUP
2012-11-08 21:18:53.190125 [DEBUG] mod_sofia.c:477
sofia/internal/501@192.168.13.18 Overriding SIP cause 504 with 408 from the
other leg
2012-11-08 21:18:53.190125 [DEBUG] mod_sofia.c:483 Channel
sofia/internal/501@192.168.13.18 hanging up, cause: RECOVERY_ON_TIMER_EXPIRE
2012-11-08 21:18:53.190125 [DEBUG] mod_sofia.c:613 Responding to INVITE
with: 408
2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:48
sofia/internal/501@192.168.13.18 Standard HANGUP, cause:
RECOVERY_ON_TIMER_EXPIRE
2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:638
(sofia/internal/501@192.168.13.18) State HANGUP going to sleep
2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:429
(sofia/internal/501@192.168.13.18) State Change CS_HANGUP -> CS_REPORTING
2012-11-08 21:18:53.190125 [DEBUG] switch_core_session.c:1210 Send signal
sofia/internal/501@192.168.13.18 [BREAK]
2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:398
(sofia/internal/501@192.168.13.18) Running State Change CS_REPORTING
2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:703
(sofia/internal/501@192.168.13.18) State REPORTING
2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:92
sofia/internal/501@192.168.13.18 Standard REPORTING, cause:
RECOVERY_ON_TIMER_EXPIRE
2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:703
(sofia/internal/501@192.168.13.18) State REPORTING going to sleep
2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:423
(sofia/internal/501@192.168.13.18) State Change CS_REPORTING -> CS_DESTROY
2012-11-08 21:18:53.190125 [DEBUG] switch_core_session.c:1210 Send signal
sofia/internal/501@192.168.13.18 [BREAK]
2012-11-08 21:18:53.190125 [DEBUG] switch_core_session.c:1415 Session 29
(sofia/internal/501@192.168.13.18) Locked, Waiting on external entities
2012-11-08 21:18:53.190125 [NOTICE] switch_core_session.c:1433 Session 29
(sofia/internal/501@192.168.13.18) Ended
2012-11-08 21:18:53.190125 [NOTICE] switch_core_session.c:1437 Close Channel
sofia/internal/501@192.168.13.18 [CS_DESTROY]
2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:527
(sofia/internal/501@192.168.13.18) Callstate Change HANGUP -> DOWN
2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:530
(sofia/internal/501@192.168.13.18) Running State Change CS_DESTROY
2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:540
(sofia/internal/501@192.168.13.18) State DESTROY
2012-11-08 21:18:53.190125 [DEBUG] mod_sofia.c:376
sofia/internal/501@192.168.13.18 SOFIA DESTROY
2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:99
sofia/internal/501@192.168.13.18 Standard DESTROY
2012-11-08 21:18:53.190125 [DEBUG] switch_core_state_machine.c:540
(sofia/internal/501@192.168.13.18) State DESTROY going to sleep





--
View this message in context: http://freeswitch-users.2379917.n2.nabble.com/problem-with-receiving-and-sending-faxes-tp7584436.html
Sent from the freeswitch-users mailing list archive at Nabble.com.

_________________________________________________________________________
Professional FreeSWITCH Consulting Services:
consulting@freeswitch.org
http://www.freeswitchsolutions.com

FreeSWITCH-powered IP PBX: The CudaTel Communication Server
http://www.cudatel.com

Official FreeSWITCH Sites
http://www.freeswitch.org
http://wiki.freeswitch.org
http://www.cluecon.com

FreeSWITCH-users mailing list
FreeSWITCH-users@lists.freeswitch.org
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
http://www.freeswitch.org



--
Michael S Collins
Twitter: @mercutioviz
http://www.FreeSWITCH.org
http://www.ClueCon.com
http://www.OSTAG.org