[Freeswitch-users] problem with receiving and sending faxes

sterned sterned at xakep.ru
Thu Nov 8 21:19:54 MSK 2012


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.



Join us at ClueCon 2011 Aug 9-11, 2011
More information about the FreeSWITCH-users mailing list