Hi people! I've set up Freeswitch with mod_spandsp and hylafax and the modems are running (initialized) and great so far. Now, when I want to send a fax, hylafax aborts all the time and I am not getting smart. http://permalink.gmane.org/gmane.comp.telephony.fax.hylafax.user/36639 Any ideas what it could be?! Here is the log from the fs_console: 2012-12-06 11:13:49.936819 [DEBUG] mod_spandsp_modem.c:1070 Modem /dev/FS0 [ONHOOK] - Hanging up 2012-12-06 11:13:49.936819 [DEBUG] mod_spandsp_modem.c:1076 Modem /dev/FS0 [ONHOOK] - Changing state to HANGUP 2012-12-06 11:13:49.936819 [DEBUG] mod_spandsp_modem.c:1095 Modem /dev/FS0 [HANGUP] - Changing state to ONHOOK 2012-12-06 11:13:54.456814 [DEBUG] mod_spandsp_modem.c:1044 Modem /dev/FS0 [ONHOOK] - Dialing '1xxxxxxxxxxxxx' 2012-12-06 11:13:54.456814 [DEBUG] mod_spandsp_modem.c:1046 Modem /dev/FS0 [ONHOOK] - Changing state to DIALING 2012-12-06 11:13:54.456814 [NOTICE] switch_channel.c:941 New Channel modem/0/1xxxxxxxxxxxxx [585f9ebe-85fb-4152-b055-99fb72bf22ed] 2012-12-06 11:13:54.456814 [DEBUG] mod_spandsp_modem.c:769 modem/0/1xxxxxxxxxxxxx setup codec L16/8000/20 2012-12-06 11:13:54.456814 [DEBUG] mod_spandsp_modem.c:1003 (modem/0/1xxxxxxxxxxxxx) State Change CS_NEW -> CS_INIT 2012-12-06 11:13:54.456814 [DEBUG] switch_core_session.c:1229 Send signal modem/0/1xxxxxxxxxxxxx [BREAK] 2012-12-06 11:13:54.456814 [DEBUG] mod_spandsp_modem.c:581 modem/0/1xxxxxxxxxxxxx CHANNEL KILL 2012-12-06 11:13:54.456814 [DEBUG] switch_channel.c:1108 EXPORT (export_vars) [rtp_autoflush_during_bridge]=[false] 2012-12-06 11:13:54.456814 [DEBUG] switch_core_state_machine.c:385 (modem/0/1xxxxxxxxxxxxx) Running State Change CS_INIT 2012-12-06 11:13:54.456814 [DEBUG] switch_core_state_machine.c:424 (modem/0/1xxxxxxxxxxxxx) State INIT 2012-12-06 11:13:54.456814 [DEBUG] mod_spandsp_modem.c:484 (modem/0/1xxxxxxxxxxxxx) State Change CS_INIT -> CS_ROUTING 2012-12-06 11:13:54.456814 [DEBUG] switch_core_session.c:1229 Send signal modem/0/1xxxxxxxxxxxxx [BREAK] 2012-12-06 11:13:54.456814 [DEBUG] mod_spandsp_modem.c:581 modem/0/1xxxxxxxxxxxxx CHANNEL KILL 2012-12-06 11:13:54.456814 [DEBUG] switch_core_state_machine.c:424 (modem/0/1xxxxxxxxxxxxx) State INIT going to sleep 2012-12-06 11:13:54.456814 [DEBUG] switch_core_state_machine.c:385 (modem/0/1xxxxxxxxxxxxx) Running State Change CS_ROUTING 2012-12-06 11:13:54.456814 [DEBUG] switch_channel.c:1934 (modem/0/1xxxxxxxxxxxxx) Callstate Change DOWN -> RINGING 2012-12-06 11:13:54.456814 [DEBUG] switch_core_state_machine.c:433 (modem/0/1xxxxxxxxxxxxx) State ROUTING 2012-12-06 11:13:54.456814 [DEBUG] switch_core_state_machine.c:104 modem/0/1xxxxxxxxxxxxx Standard ROUTING 2012-12-06 11:13:54.456814 [INFO] mod_dialplan_xml.c:485 Processing FSModem <FS0>->1xxxxxxxxxxxxx in context default Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->unloop] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->tod_example] continue=true Dialplan: modem/0/1xxxxxxxxxxxxx Date/Time Match (PASS) [tod_example] break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx Action set(open=true) Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->holiday_example] continue=true Dialplan: modem/0/1xxxxxxxxxxxxx Date/TimeMatch (FAIL) [holiday_example] break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->global-intercept] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [global-intercept] destination_number(1xxxxxxxxxxxxx) =~ /^886$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->group-intercept] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [group-intercept] destination_number(1xxxxxxxxxxxxx) =~ /^\*8$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->intercept-ext] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [intercept-ext] destination_number(1xxxxxxxxxxxxx) =~ /^\*\*(\d+)$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->redial] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [redial] destination_number(1xxxxxxxxxxxxx) =~ /^(redial|870)$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->global] continue=true Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [global] ${sip_has_crypto}() =~ /^(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)$/ break=never Dialplan: modem/0/1xxxxxxxxxxxxx Absolute Condition [global] Dialplan: modem/0/1xxxxxxxxxxxxx Action hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid}) Dialplan: modem/0/1xxxxxxxxxxxxx Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number}) Dialplan: modem/0/1xxxxxxxxxxxxx Action hash(insert/${domain_name}-last_dial/global/${uuid}) Dialplan: modem/0/1xxxxxxxxxxxxx Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->snom-demo-2] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [snom-demo-2] destination_number(1xxxxxxxxxxxxx) =~ /^9001$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->snom-demo-1] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [snom-demo-1] destination_number(1xxxxxxxxxxxxx) =~ /^9000$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->eavesdrop] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [eavesdrop] destination_number(1xxxxxxxxxxxxx) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->eavesdrop] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [eavesdrop] destination_number(1xxxxxxxxxxxxx) =~ /^779$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->call_return] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [call_return] destination_number(1xxxxxxxxxxxxx) =~ /^\*69$|^869$|^lcr$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->del-group] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [del-group] destination_number(1xxxxxxxxxxxxx) =~ /^80(\d{2})$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->add-group] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [add-group] destination_number(1xxxxxxxxxxxxx) =~ /^81(\d{2})$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->call-group-simo] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [call-group-simo] destination_number(1xxxxxxxxxxxxx) =~ /^82(\d{2})$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->call-group-order] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [call-group-order] destination_number(1xxxxxxxxxxxxx) =~ /^83(\d{2})$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->extension-intercom] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [extension-intercom] destination_number(1xxxxxxxxxxxxx) =~ /^8(10[01][0-9])$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->Local_Extension] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [Local_Extension] destination_number(1xxxxxxxxxxxxx) =~ /^(10[01][0-9])$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->Local_Extension_Skinny] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [Local_Extension_Skinny] destination_number(1xxxxxxxxxxxxx) =~ /^(11[01][0-9])$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->group_dial_sales] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [group_dial_sales] destination_number(1xxxxxxxxxxxxx) =~ /^2000$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->group_dial_support] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [group_dial_support] destination_number(1xxxxxxxxxxxxx) =~ /^2001$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->group_dial_billing] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [group_dial_billing] destination_number(1xxxxxxxxxxxxx) =~ /^2002$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->operator] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [operator] destination_number(1xxxxxxxxxxxxx) =~ /^(operator|0)$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->vmain] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [vmain] destination_number(1xxxxxxxxxxxxx) =~ /^vmain$|^4000$|^\*98$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->sip_uri] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [sip_uri] destination_number(1xxxxxxxxxxxxx) =~ /^sip:(.*)$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->nb_conferences] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [nb_conferences] destination_number(1xxxxxxxxxxxxx) =~ /^(30\d{2})$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->wb_conferences] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [wb_conferences] destination_number(1xxxxxxxxxxxxx) =~ /^(31\d{2})$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->uwb_conferences] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [uwb_conferences] destination_number(1xxxxxxxxxxxxx) =~ /^(32\d{2})$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->cdquality_conferences] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [cdquality_conferences] destination_number(1xxxxxxxxxxxxx) =~ /^(33\d{2})$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->freeswitch_public_conf_via_sip] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [freeswitch_public_conf_via_sip] destination_number(1xxxxxxxxxxxxx) =~ /^9(888|8888|1616|3232)$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->mad_boss_intercom] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [mad_boss_intercom] destination_number(1xxxxxxxxxxxxx) =~ /^0911$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->mad_boss_intercom] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [mad_boss_intercom] destination_number(1xxxxxxxxxxxxx) =~ /^0912$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->mad_boss] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [mad_boss] destination_number(1xxxxxxxxxxxxx) =~ /^0913$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->ivr_demo] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [ivr_demo] destination_number(1xxxxxxxxxxxxx) =~ /^5000$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->dynamic_conference] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [dynamic_conference] destination_number(1xxxxxxxxxxxxx) =~ /^5001$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->rtp_multicast_page] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [rtp_multicast_page] destination_number(1xxxxxxxxxxxxx) =~ /^pagegroup$|^7243$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->park] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [park] destination_number(1xxxxxxxxxxxxx) =~ /^5900$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->unpark] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [unpark] destination_number(1xxxxxxxxxxxxx) =~ /^5901$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->valet_park] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [valet_park] destination_number(1xxxxxxxxxxxxx) =~ /^(6000)$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->valet_park] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [valet_park] destination_number(1xxxxxxxxxxxxx) =~ /^(60\d[1-9])$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->park] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [park] source(mod_spandsp) =~ /mod_sofia/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->unpark] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [unpark] source(mod_spandsp) =~ /mod_sofia/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->park] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [park] source(mod_spandsp) =~ /mod_sofia/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->unpark] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [unpark] source(mod_spandsp) =~ /mod_sofia/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->wait] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [wait] destination_number(1xxxxxxxxxxxxx) =~ /^wait$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->fax_receive] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [fax_receive] destination_number(1xxxxxxxxxxxxx) =~ /^9178$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->fax_transmit] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [fax_transmit] destination_number(1xxxxxxxxxxxxx) =~ /^9179$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->ringback_180] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [ringback_180] destination_number(1xxxxxxxxxxxxx) =~ /^9180$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->ringback_183_uk_ring] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [ringback_183_uk_ring] destination_number(1xxxxxxxxxxxxx) =~ /^9181$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->ringback_183_music_ring] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [ringback_183_music_ring] destination_number(1xxxxxxxxxxxxx) =~ /^9182$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->ringback_post_answer_uk_ring] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [ringback_post_answer_uk_ring] destination_number(1xxxxxxxxxxxxx) =~ /^9183$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->ringback_post_answer_music] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [ringback_post_answer_music] destination_number(1xxxxxxxxxxxxx) =~ /^9184$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->ClueCon] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [ClueCon] destination_number(1xxxxxxxxxxxxx) =~ /^9191$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->show_info] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [show_info] destination_number(1xxxxxxxxxxxxx) =~ /^9192$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->video_record] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [video_record] destination_number(1xxxxxxxxxxxxx) =~ /^9193$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->video_playback] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [video_playback] destination_number(1xxxxxxxxxxxxx) =~ /^9194$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->delay_echo] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [delay_echo] destination_number(1xxxxxxxxxxxxx) =~ /^9195$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->echo] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [echo] destination_number(1xxxxxxxxxxxxx) =~ /^9196$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->milliwatt] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [milliwatt] destination_number(1xxxxxxxxxxxxx) =~ /^9197$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->tone_stream] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [tone_stream] destination_number(1xxxxxxxxxxxxx) =~ /^9198$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->zrtp_enrollement] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [zrtp_enrollement] destination_number(1xxxxxxxxxxxxx) =~ /^9787$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->hold_music] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [hold_music] destination_number(1xxxxxxxxxxxxx) =~ /^9664$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->laugh break] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [laugh break] destination_number(1xxxxxxxxxxxxx) =~ /^9386$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->Talking Clock Time] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [Talking Clock Time] destination_number(1xxxxxxxxxxxxx) =~ /^9170$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->Talking Clock Date] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [Talking Clock Date] destination_number(1xxxxxxxxxxxxx) =~ /^9171$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->Talking Clock Date and Time] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [Talking Clock Date and Time] destination_number(1xxxxxxxxxxxxx) =~ /^9172$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->sipgate0] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [sipgate0] destination_number(1xxxxxxxxxxxxx) =~ /^2(\d{3,})/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->sipgate1] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [sipgate1] destination_number(1xxxxxxxxxxxxx) =~ /^3(\d{3,})/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->ABX] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [ABX] destination_number(1xxxxxxxxxxxxx) =~ /^(90)$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->ABX2] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [ABX2] destination_number(1xxxxxxxxxxxxx) =~ /^(91)$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->FSX] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [FSX] destination_number(1xxxxxxxxxxxxx) =~ /^(92)$/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->easybell0] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (FAIL) [easybell0] destination_number(1xxxxxxxxxxxxx) =~ /^0(\d{3,})/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx parsing [default->easybell1] continue=false Dialplan: modem/0/1xxxxxxxxxxxxx Regex (PASS) [easybell1] destination_number(1xxxxxxxxxxxxx) =~ /^1(\d{3,})/ break=on-false Dialplan: modem/0/1xxxxxxxxxxxxx Action set(effective_caller_id_number=${outbound_caller_id_number}) Dialplan: modem/0/1xxxxxxxxxxxxx Action set(absolute_codec_string=PCMA) Dialplan: modem/0/1xxxxxxxxxxxxx Action set(fax_enable_t38=true) Dialplan: modem/0/1xxxxxxxxxxxxx Action set(fax_enable_t38_request=true) Dialplan: modem/0/1xxxxxxxxxxxxx Action set(execute_on_answer=t38_gateway self) Dialplan: modem/0/1xxxxxxxxxxxxx Action bridge(sofia/gateway/easybell1/xxxxxxxxxxxxx) Dialplan: modem/0/1xxxxxxxxxxxxx Action hangup() 2012-12-06 11:13:54.456814 [DEBUG] switch_core_state_machine.c:154 (modem/0/1xxxxxxxxxxxxx) State Change CS_ROUTING -> CS_EXECUTE 2012-12-06 11:13:54.456814 [DEBUG] switch_core_session.c:1229 Send signal modem/0/1xxxxxxxxxxxxx [BREAK] 2012-12-06 11:13:54.456814 [DEBUG] mod_spandsp_modem.c:581 modem/0/1xxxxxxxxxxxxx CHANNEL KILL 2012-12-06 11:13:54.456814 [DEBUG] switch_core_state_machine.c:433 (modem/0/1xxxxxxxxxxxxx) State ROUTING going to sleep 2012-12-06 11:13:54.456814 [DEBUG] switch_core_state_machine.c:385 (modem/0/1xxxxxxxxxxxxx) Running State Change CS_EXECUTE 2012-12-06 11:13:54.456814 [DEBUG] switch_core_state_machine.c:440 (modem/0/1xxxxxxxxxxxxx) State EXECUTE 2012-12-06 11:13:54.456814 [DEBUG] mod_spandsp_modem.c:514 modem/0/1xxxxxxxxxxxxx CHANNEL EXECUTE 2012-12-06 11:13:54.456814 [DEBUG] switch_core_state_machine.c:196 modem/0/1xxxxxxxxxxxxx Standard EXECUTE EXECUTE modem/0/1xxxxxxxxxxxxx set(open=true) 2012-12-06 11:13:54.456814 [DEBUG] mod_dptools.c:1319 modem/0/1xxxxxxxxxxxxx SET [open]=[true] EXECUTE modem/0/1xxxxxxxxxxxxx hash(insert/212.255.30.34-spymap/FS0/585f9ebe-85fb-4152-b055-99fb72bf22ed) EXECUTE modem/0/1xxxxxxxxxxxxx hash(insert/212.255.30.34-last_dial/FS0/1xxxxxxxxxxxxx) EXECUTE modem/0/1xxxxxxxxxxxxx hash(insert/212.255.30.34-last_dial/global/585f9ebe-85fb-4152-b055-99fb72bf22ed) EXECUTE modem/0/1xxxxxxxxxxxxx export(RFC2822_DATE=Thu, 06 Dec 2012 11:13:54 +0100) 2012-12-06 11:13:54.456814 [DEBUG] switch_channel.c:1108 EXPORT (export_vars) [RFC2822_DATE]=[Thu, 06 Dec 2012 11:13:54 +0100] EXECUTE modem/0/1xxxxxxxxxxxxx set(effective_caller_id_number=) 2012-12-06 11:13:54.456814 [DEBUG] mod_dptools.c:1319 modem/0/1xxxxxxxxxxxxx SET [effective_caller_id_number]=[UNDEF] EXECUTE modem/0/1xxxxxxxxxxxxx set(absolute_codec_string=PCMA) 2012-12-06 11:13:54.456814 [DEBUG] mod_dptools.c:1319 modem/0/1xxxxxxxxxxxxx SET [absolute_codec_string]=[PCMA] EXECUTE modem/0/1xxxxxxxxxxxxx set(fax_enable_t38=true) 2012-12-06 11:13:54.456814 [DEBUG] mod_dptools.c:1319 modem/0/1xxxxxxxxxxxxx SET [fax_enable_t38]=[true] EXECUTE modem/0/1xxxxxxxxxxxxx set(fax_enable_t38_request=true) 2012-12-06 11:13:54.456814 [DEBUG] mod_dptools.c:1319 modem/0/1xxxxxxxxxxxxx SET [fax_enable_t38_request]=[true] EXECUTE modem/0/1xxxxxxxxxxxxx set(execute_on_answer=t38_gateway self) 2012-12-06 11:13:54.456814 [DEBUG] mod_dptools.c:1319 modem/0/1xxxxxxxxxxxxx SET [execute_on_answer]=[t38_gateway self] EXECUTE modem/0/1xxxxxxxxxxxxx bridge(sofia/gateway/easybell1/xxxxxxxxxxxxx) 2012-12-06 11:13:54.456814 [DEBUG] switch_channel.c:1062 modem/0/1xxxxxxxxxxxxx EXPORTING[export_vars] [rtp_autoflush_during_bridge]=[false] to event 2012-12-06 11:13:54.456814 [DEBUG] switch_channel.c:1062 modem/0/1xxxxxxxxxxxxx EXPORTING[export_vars] [RFC2822_DATE]=[Thu, 06 Dec 2012 11:13:54 +0100] to event 2012-12-06 11:13:54.456814 [DEBUG] switch_ivr_originate.c:1961 Parsing global variables 2012-12-06 11:13:54.456814 [NOTICE] switch_channel.c:941 New Channel sofia/external/xxxxxxxxxxxxx [b0ac6763-2068-4574-849c-f443d99e978a] 2012-12-06 11:13:54.456814 [DEBUG] mod_sofia.c:4796 (sofia/external/xxxxxxxxxxxxx) State Change CS_NEW -> CS_INIT 2012-12-06 11:13:54.456814 [DEBUG] switch_core_session.c:1229 Send signal sofia/external/xxxxxxxxxxxxx [BREAK] 2012-12-06 11:13:54.456814 [DEBUG] switch_core_state_machine.c:385 (sofia/external/xxxxxxxxxxxxx) Running State Change CS_INIT 2012-12-06 11:13:54.456814 [DEBUG] switch_core_state_machine.c:424 (sofia/external/xxxxxxxxxxxxx) State INIT 2012-12-06 11:13:54.456814 [DEBUG] mod_sofia.c:85 sofia/external/xxxxxxxxxxxxx SOFIA INIT 2012-12-06 11:13:54.456814 [DEBUG] sofia_glue.c:2609 Local SDP: v=0 o=FreeSWITCH 1354769940 1354769941 IN IP4 212.255.30.34 s=FreeSWITCH c=IN IP4 212.255.30.34 t=0 0 m=audio 18894 RTP/AVP 98 0 8 3 101 13 a=rtpmap:98 L16/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv 2012-12-06 11:13:54.456814 [DEBUG] mod_sofia.c:125 (sofia/external/xxxxxxxxxxxxx) State Change CS_INIT -> CS_ROUTING 2012-12-06 11:13:54.456814 [DEBUG] switch_core_session.c:1229 Send signal sofia/external/xxxxxxxxxxxxx [BREAK] 2012-12-06 11:13:54.456814 [DEBUG] switch_core_state_machine.c:424 (sofia/external/xxxxxxxxxxxxx) State INIT going to sleep 2012-12-06 11:13:54.456814 [DEBUG] switch_core_state_machine.c:385 (sofia/external/xxxxxxxxxxxxx) Running State Change CS_ROUTING 2012-12-06 11:13:54.456814 [DEBUG] switch_channel.c:1934 (sofia/external/xxxxxxxxxxxxx) Callstate Change DOWN -> RINGING 2012-12-06 11:13:54.456814 [DEBUG] switch_core_state_machine.c:433 (sofia/external/xxxxxxxxxxxxx) State ROUTING 2012-12-06 11:13:54.456814 [DEBUG] mod_sofia.c:148 sofia/external/xxxxxxxxxxxxx SOFIA ROUTING 2012-12-06 11:13:54.456814 [DEBUG] switch_ivr_originate.c:67 (sofia/external/xxxxxxxxxxxxx) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2012-12-06 11:13:54.456814 [DEBUG] switch_core_session.c:1229 Send signal sofia/external/xxxxxxxxxxxxx [BREAK] 2012-12-06 11:13:54.456814 [DEBUG] switch_core_state_machine.c:433 (sofia/external/xxxxxxxxxxxxx) State ROUTING going to sleep 2012-12-06 11:13:54.456814 [DEBUG] switch_core_state_machine.c:385 (sofia/external/xxxxxxxxxxxxx) Running State Change CS_CONSUME_MEDIA 2012-12-06 11:13:54.456814 [DEBUG] switch_core_state_machine.c:452 (sofia/external/xxxxxxxxxxxxx) State CONSUME_MEDIA 2012-12-06 11:13:54.456814 [DEBUG] switch_core_state_machine.c:452 (sofia/external/xxxxxxxxxxxxx) State CONSUME_MEDIA going to sleep 2012-12-06 11:13:54.456814 [DEBUG] switch_core_session.c:924 Send signal sofia/external/xxxxxxxxxxxxx [BREAK] 2012-12-06 11:13:54.456814 [DEBUG] sofia.c:6055 Channel sofia/external/xxxxxxxxxxxxx entering state [calling][0] 2012-12-06 11:13:54.496801 [DEBUG] switch_core_session.c:924 Send signal sofia/external/xxxxxxxxxxxxx [BREAK] 2012-12-06 11:13:54.496801 [DEBUG] switch_core_session.c:924 Send signal sofia/external/xxxxxxxxxxxxx [BREAK] 2012-12-06 11:13:54.496801 [DEBUG] sofia.c:6055 Channel sofia/external/xxxxxxxxxxxxx entering state [calling][0] 2012-12-06 11:13:58.656800 [DEBUG] switch_core_session.c:924 Send signal sofia/external/xxxxxxxxxxxxx [BREAK] 2012-12-06 11:13:58.656800 [DEBUG] switch_core_session.c:924 Send signal sofia/external/xxxxxxxxxxxxx [BREAK] 2012-12-06 11:13:58.656800 [DEBUG] sofia.c:6055 Channel sofia/external/xxxxxxxxxxxxx entering state [proceeding][183] 2012-12-06 11:13:58.656800 [DEBUG] sofia.c:6066 Remote SDP: v=0 o=- 7632 1354788832 IN IP4 212.172.97.124 s=- c=IN IP4 212.172.97.124 t=0 0 m=audio 32392 RTP/AVP 8 101 a=rtpmap:101 telephone-event/8000/1 a=fmtp:101 0-15 a=ptime:20 a=nortpproxy:yes 2012-12-06 11:13:58.656800 [DEBUG] sofia_glue.c:3948 Looking for zrtp-hash 2012-12-06 11:13:58.656800 [DEBUG] sofia_glue.c:3926 Deciding whether to pass zrtp-hash between legs 2012-12-06 11:13:58.656800 [DEBUG] sofia_glue.c:3928 CF_ZRTP_PASSTHRU_REQ not set, so not propagating zrtp-hash 2012-12-06 11:13:58.656800 [DEBUG] sofia_glue.c:3948 Looking for zrtp-hash 2012-12-06 11:13:58.656800 [DEBUG] sofia_glue.c:3926 Deciding whether to pass zrtp-hash between legs 2012-12-06 11:13:58.656800 [DEBUG] sofia_glue.c:3928 CF_ZRTP_PASSTHRU_REQ not set, so not propagating zrtp-hash 2012-12-06 11:13:58.656800 [DEBUG] sofia_glue.c:5044 Audio Codec Compare [PCMA:8:8000:20:64000]/[L16:70:8000:20:128000] 2012-12-06 11:13:58.656800 [DEBUG] sofia_glue.c:5044 Audio Codec Compare [PCMA:8:8000:20:64000]/[PCMU:0:8000:20:64000] 2012-12-06 11:13:58.656800 [DEBUG] sofia_glue.c:5044 Audio Codec Compare [PCMA:8:8000:20:64000]/[PCMA:8:8000:20:64000] 2012-12-06 11:13:58.656800 [DEBUG] sofia_glue.c:3027 Set Codec sofia/external/xxxxxxxxxxxxx PCMA/8000 20 ms 160 samples 64000 bits 2012-12-06 11:13:58.656800 [DEBUG] switch_core_codec.c:111 sofia/external/xxxxxxxxxxxxx Original read codec set to PCMA:8 2012-12-06 11:13:58.656800 [DEBUG] sofia_glue.c:5158 Set 2833 dtmf send payload to 101 2012-12-06 11:13:58.656800 [DEBUG] sofia_glue.c:3276 AUDIO RTP [sofia/external/xxxxxxxxxxxxx] 212.255.30.34 port 18894 -> 212.172.97.124 port 32392 codec: 8 ms: 20 2012-12-06 11:13:58.656800 [DEBUG] switch_rtp.c:1927 Starting timer [soft] 160 bytes per 20ms 2012-12-06 11:13:58.656800 [DEBUG] sofia_glue.c:3540 Set 2833 dtmf send payload to 101 2012-12-06 11:13:58.656800 [DEBUG] sofia_glue.c:3546 Set 2833 dtmf receive payload to 101 2012-12-06 11:13:58.656800 [DEBUG] sofia_glue.c:3573 sofia/external/xxxxxxxxxxxxx Set rtp dtmf delay to 40 2012-12-06 11:13:58.656800 [NOTICE] sofia_glue.c:4176 Pre-Answer sofia/external/xxxxxxxxxxxxx! 2012-12-06 11:13:58.656800 [DEBUG] switch_channel.c:3057 (sofia/external/xxxxxxxxxxxxx) Callstate Change RINGING -> EARLY 2012-12-06 11:13:58.656800 [DEBUG] switch_channel.c:3099 Send signal modem/0/1xxxxxxxxxxxxx [BREAK] 2012-12-06 11:13:58.656800 [DEBUG] mod_spandsp_modem.c:581 modem/0/1xxxxxxxxxxxxx CHANNEL KILL 2012-12-06 11:13:58.656800 [DEBUG] mod_spandsp_modem.c:1131 Modem /dev/FS0 [DIALING] - RNG 0 2012-12-06 11:13:58.656800 [DEBUG] mod_spandsp_modem.c:738 Modem /dev/FS0 [DIALING] - Changing state to CONNECTED 2012-12-06 11:13:58.656800 [DEBUG] switch_core_session.c:840 Send signal sofia/external/xxxxxxxxxxxxx [BREAK] 2012-12-06 11:13:58.656800 [DEBUG] switch_core_session.c:778 Send signal modem/0/1xxxxxxxxxxxxx [BREAK] 2012-12-06 11:13:58.656800 [DEBUG] mod_spandsp_modem.c:581 modem/0/1xxxxxxxxxxxxx CHANNEL KILL 2012-12-06 11:13:58.656800 [NOTICE] switch_ivr_originate.c:3309 Pre-Answer modem/0/1xxxxxxxxxxxxx! 2012-12-06 11:13:58.656800 [DEBUG] switch_channel.c:3057 (modem/0/1xxxxxxxxxxxxx) Callstate Change RINGING -> EARLY 2012-12-06 11:13:58.656800 [DEBUG] switch_ivr_originate.c:3360 Originate Resulted in Success: [sofia/external/xxxxxxxxxxxxx] 2012-12-06 11:13:58.656800 [DEBUG] switch_core_session.c:778 Send signal sofia/external/xxxxxxxxxxxxx [BREAK] 2012-12-06 11:13:58.656800 [DEBUG] switch_core_session.c:840 Send signal sofia/external/xxxxxxxxxxxxx [BREAK] 2012-12-06 11:13:58.656800 [DEBUG] switch_core_session.c:778 Send signal modem/0/1xxxxxxxxxxxxx [BREAK] 2012-12-06 11:13:58.656800 [DEBUG] mod_spandsp_modem.c:581 modem/0/1xxxxxxxxxxxxx CHANNEL KILL 2012-12-06 11:13:58.656800 [DEBUG] switch_ivr_bridge.c:1359 (sofia/external/xxxxxxxxxxxxx) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA 2012-12-06 11:13:58.656800 [DEBUG] switch_core_session.c:1229 Send signal sofia/external/xxxxxxxxxxxxx [BREAK] 2012-12-06 11:13:58.656800 [DEBUG] switch_core_state_machine.c:385 (sofia/external/xxxxxxxxxxxxx) Running State Change CS_EXCHANGE_MEDIA 2012-12-06 11:13:58.656800 [DEBUG] switch_core_state_machine.c:443 (sofia/external/xxxxxxxxxxxxx) State EXCHANGE_MEDIA 2012-12-06 11:13:58.656800 [DEBUG] mod_sofia.c:652 SOFIA EXCHANGE_MEDIA 2012-12-06 11:13:58.696829 [DEBUG] switch_rtp.c:3594 Correct ip/port confirmed. 2012-12-06 11:13:58.936865 [DEBUG] switch_core_session.c:924 Send signal sofia/external/xxxxxxxxxxxxx [BREAK] 2012-12-06 11:13:58.936865 [DEBUG] switch_core_session.c:924 Send signal sofia/external/xxxxxxxxxxxxx [BREAK] 2012-12-06 11:13:58.956952 [DEBUG] sofia.c:6048 Channel sofia/external/xxxxxxxxxxxxx skipping state [proceeding][180] 2012-12-06 11:13:59.956847 [DEBUG] switch_core_session.c:924 Send signal sofia/external/xxxxxxxxxxxxx [BREAK] 2012-12-06 11:13:59.956847 [DEBUG] switch_core_session.c:924 Send signal sofia/external/xxxxxxxxxxxxx [BREAK] 2012-12-06 11:13:59.956847 [DEBUG] switch_core_session.c:924 Send signal sofia/external/xxxxxxxxxxxxx [BREAK] 2012-12-06 11:13:59.976824 [DEBUG] sofia.c:6055 Channel sofia/external/xxxxxxxxxxxxx entering state [terminated][486] 2012-12-06 11:13:59.976824 [DEBUG] switch_channel.c:2914 (sofia/external/xxxxxxxxxxxxx) Callstate Change EARLY -> HANGUP 2012-12-06 11:13:59.976824 [NOTICE] sofia.c:6847 Hangup sofia/external/xxxxxxxxxxxxx [CS_EXCHANGE_MEDIA] [USER_BUSY] 2012-12-06 11:13:59.976824 [DEBUG] switch_channel.c:2937 Send signal sofia/external/xxxxxxxxxxxxx [KILL] 2012-12-06 11:13:59.976824 [DEBUG] switch_core_session.c:1229 Send signal sofia/external/xxxxxxxxxxxxx [BREAK] 2012-12-06 11:13:59.976824 [DEBUG] switch_ivr_bridge.c:588 BRIDGE THREAD DONE [sofia/external/xxxxxxxxxxxxx] 2012-12-06 11:13:59.976824 [DEBUG] switch_ivr_bridge.c:613 Send signal modem/0/1xxxxxxxxxxxxx [BREAK] 2012-12-06 11:13:59.976824 [DEBUG] mod_spandsp_modem.c:581 modem/0/1xxxxxxxxxxxxx CHANNEL KILL 2012-12-06 11:13:59.976824 [DEBUG] switch_core_state_machine.c:443 (sofia/external/xxxxxxxxxxxxx) State EXCHANGE_MEDIA going to sleep 2012-12-06 11:13:59.976824 [DEBUG] switch_core_state_machine.c:385 (sofia/external/xxxxxxxxxxxxx) Running State Change CS_HANGUP 2012-12-06 11:13:59.976824 [DEBUG] switch_core_state_machine.c:625 (sofia/external/xxxxxxxxxxxxx) State HANGUP 2012-12-06 11:13:59.976824 [DEBUG] mod_sofia.c:474 Channel sofia/external/xxxxxxxxxxxxx hanging up, cause: USER_BUSY 2012-12-06 11:13:59.976824 [DEBUG] switch_core_state_machine.c:47 sofia/external/xxxxxxxxxxxxx Standard HANGUP, cause: USER_BUSY 2012-12-06 11:13:59.976824 [DEBUG] switch_core_state_machine.c:625 (sofia/external/xxxxxxxxxxxxx) State HANGUP going to sleep 2012-12-06 11:13:59.976824 [DEBUG] switch_core_state_machine.c:416 (sofia/external/xxxxxxxxxxxxx) State Change CS_HANGUP -> CS_REPORTING 2012-12-06 11:13:59.976824 [DEBUG] switch_core_session.c:1229 Send signal sofia/external/xxxxxxxxxxxxx [BREAK] 2012-12-06 11:13:59.976824 [DEBUG] switch_core_state_machine.c:385 (sofia/external/xxxxxxxxxxxxx) Running State Change CS_REPORTING 2012-12-06 11:13:59.976824 [DEBUG] switch_core_state_machine.c:685 (sofia/external/xxxxxxxxxxxxx) State REPORTING 2012-12-06 11:13:59.976824 [DEBUG] switch_core_state_machine.c:79 sofia/external/xxxxxxxxxxxxx Standard REPORTING, cause: USER_BUSY 2012-12-06 11:13:59.976824 [DEBUG] switch_core_state_machine.c:685 (sofia/external/xxxxxxxxxxxxx) State REPORTING going to sleep 2012-12-06 11:13:59.976824 [DEBUG] switch_core_state_machine.c:410 (sofia/external/xxxxxxxxxxxxx) State Change CS_REPORTING -> CS_DESTROY 2012-12-06 11:13:59.976824 [DEBUG] switch_core_session.c:1229 Send signal sofia/external/xxxxxxxxxxxxx [BREAK] 2012-12-06 11:13:59.976824 [DEBUG] switch_core_session.c:1429 Session 24 (sofia/external/xxxxxxxxxxxxx) Locked, Waiting on external entities 2012-12-06 11:13:59.996802 [DEBUG] switch_ivr_bridge.c:501 sofia/external/xxxxxxxxxxxxx ending bridge by request from write function 2012-12-06 11:13:59.996802 [DEBUG] switch_ivr_bridge.c:588 BRIDGE THREAD DONE [modem/0/1xxxxxxxxxxxxx] 2012-12-06 11:13:59.996802 [DEBUG] switch_ivr_bridge.c:613 Send signal sofia/external/xxxxxxxxxxxxx [BREAK] 2012-12-06 11:13:59.996802 [DEBUG] switch_core_session.c:778 Send signal modem/0/1xxxxxxxxxxxxx [BREAK] 2012-12-06 11:13:59.996802 [DEBUG] mod_spandsp_modem.c:581 modem/0/1xxxxxxxxxxxxx CHANNEL KILL 2012-12-06 11:13:59.996802 [NOTICE] switch_core_session.c:1447 Session 24 (sofia/external/xxxxxxxxxxxxx) Ended 2012-12-06 11:13:59.996802 [NOTICE] switch_core_session.c:1449 Close Channel sofia/external/xxxxxxxxxxxxx [CS_DESTROY] EXECUTE modem/0/1xxxxxxxxxxxxx hangup() 2012-12-06 11:13:59.996802 [DEBUG] switch_channel.c:2914 (modem/0/1xxxxxxxxxxxxx) Callstate Change EARLY -> HANGUP 2012-12-06 11:13:59.996802 [DEBUG] switch_core_state_machine.c:514 (sofia/external/xxxxxxxxxxxxx) Callstate Change HANGUP -> DOWN 2012-12-06 11:13:59.996802 [NOTICE] mod_dptools.c:1134 Hangup modem/0/1xxxxxxxxxxxxx [CS_EXECUTE] [NORMAL_CLEARING] 2012-12-06 11:13:59.996802 [DEBUG] switch_core_state_machine.c:517 (sofia/external/xxxxxxxxxxxxx) Running State Change CS_DESTROY 2012-12-06 11:13:59.996802 [DEBUG] switch_core_state_machine.c:527 (sofia/external/xxxxxxxxxxxxx) State DESTROY 2012-12-06 11:13:59.996802 [DEBUG] mod_sofia.c:374 sofia/external/xxxxxxxxxxxxx SOFIA DESTROY 2012-12-06 11:13:59.996802 [DEBUG] switch_core_state_machine.c:86 sofia/external/xxxxxxxxxxxxx Standard DESTROY 2012-12-06 11:13:59.996802 [DEBUG] switch_core_state_machine.c:527 (sofia/external/xxxxxxxxxxxxx) State DESTROY going to sleep 2012-12-06 11:13:59.996802 [DEBUG] switch_channel.c:2937 Send signal modem/0/1xxxxxxxxxxxxx [KILL] 2012-12-06 11:13:59.996802 [DEBUG] mod_spandsp_modem.c:581 modem/0/1xxxxxxxxxxxxx CHANNEL KILL 2012-12-06 11:13:59.996802 [DEBUG] switch_core_session.c:1229 Send signal modem/0/1xxxxxxxxxxxxx [BREAK] 2012-12-06 11:13:59.996802 [DEBUG] mod_spandsp_modem.c:581 modem/0/1xxxxxxxxxxxxx CHANNEL KILL 2012-12-06 11:13:59.996802 [DEBUG] switch_core_session.c:2345 modem/0/1xxxxxxxxxxxxx skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2012-12-06 11:13:59.996802 [DEBUG] switch_core_state_machine.c:440 (modem/0/1xxxxxxxxxxxxx) State EXECUTE going to sleep 2012-12-06 11:13:59.996802 [DEBUG] switch_core_state_machine.c:385 (modem/0/1xxxxxxxxxxxxx) Running State Change CS_HANGUP 2012-12-06 11:13:59.996802 [DEBUG] switch_core_state_machine.c:625 (modem/0/1xxxxxxxxxxxxx) State HANGUP 2012-12-06 11:13:59.996802 [DEBUG] mod_spandsp_modem.c:553 modem/0/1xxxxxxxxxxxxx CHANNEL HANGUP 2012-12-06 11:13:59.996802 [DEBUG] mod_spandsp_modem.c:1070 Modem /dev/FS0 [CONNECTED] - Hanging up 2012-12-06 11:13:59.996802 [DEBUG] mod_spandsp_modem.c:1076 Modem /dev/FS0 [CONNECTED] - Changing state to HANGUP 2012-12-06 11:13:59.996802 [DEBUG] mod_spandsp_modem.c:1095 Modem /dev/FS0 [HANGUP] - Changing state to ONHOOK 2012-12-06 11:13:59.996802 [DEBUG] mod_spandsp_modem.c:1131 Modem /dev/FS0 [ONHOOK] - RNG 0 2012-12-06 11:13:59.996802 [DEBUG] switch_core_state_machine.c:47 modem/0/1xxxxxxxxxxxxx Standard HANGUP, cause: NORMAL_CLEARING 2012-12-06 11:13:59.996802 [DEBUG] switch_core_state_machine.c:625 (modem/0/1xxxxxxxxxxxxx) State HANGUP going to sleep 2012-12-06 11:13:59.996802 [DEBUG] switch_core_state_machine.c:416 (modem/0/1xxxxxxxxxxxxx) State Change CS_HANGUP -> CS_REPORTING 2012-12-06 11:13:59.996802 [DEBUG] switch_core_session.c:1229 Send signal modem/0/1xxxxxxxxxxxxx [BREAK] 2012-12-06 11:13:59.996802 [DEBUG] mod_spandsp_modem.c:581 modem/0/1xxxxxxxxxxxxx CHANNEL KILL 2012-12-06 11:13:59.996802 [DEBUG] switch_core_state_machine.c:385 (modem/0/1xxxxxxxxxxxxx) Running State Change CS_REPORTING 2012-12-06 11:13:59.996802 [DEBUG] switch_core_state_machine.c:685 (modem/0/1xxxxxxxxxxxxx) State REPORTING 2012-12-06 11:13:59.996802 [DEBUG] switch_core_state_machine.c:79 modem/0/1xxxxxxxxxxxxx Standard REPORTING, cause: NORMAL_CLEARING 2012-12-06 11:13:59.996802 [DEBUG] switch_core_state_machine.c:685 (modem/0/1xxxxxxxxxxxxx) State REPORTING going to sleep 2012-12-06 11:13:59.996802 [DEBUG] switch_core_state_machine.c:410 (modem/0/1xxxxxxxxxxxxx) State Change CS_REPORTING -> CS_DESTROY 2012-12-06 11:13:59.996802 [DEBUG] switch_core_session.c:1229 Send signal modem/0/1xxxxxxxxxxxxx [BREAK] 2012-12-06 11:13:59.996802 [DEBUG] mod_spandsp_modem.c:581 modem/0/1xxxxxxxxxxxxx CHANNEL KILL 2012-12-06 11:13:59.996802 [DEBUG] switch_core_session.c:1429 Session 23 (modem/0/1xxxxxxxxxxxxx) Locked, Waiting on external entities 2012-12-06 11:13:59.996802 [NOTICE] switch_core_session.c:1447 Session 23 (modem/0/1xxxxxxxxxxxxx) Ended 2012-12-06 11:13:59.996802 [NOTICE] switch_core_session.c:1449 Close Channel modem/0/1xxxxxxxxxxxxx [CS_DESTROY] 2012-12-06 11:13:59.996802 [DEBUG] switch_core_state_machine.c:514 (modem/0/1xxxxxxxxxxxxx) Callstate Change HANGUP -> DOWN 2012-12-06 11:13:59.996802 [DEBUG] switch_core_state_machine.c:517 (modem/0/1xxxxxxxxxxxxx) Running State Change CS_DESTROY 2012-12-06 11:13:59.996802 [DEBUG] switch_core_state_machine.c:527 (modem/0/1xxxxxxxxxxxxx) State DESTROY 2012-12-06 11:13:59.996802 [DEBUG] mod_spandsp_modem.c:534 Modem /dev/FS0 [ONHOOK] - Changing state to ONHOOK 2012-12-06 11:13:59.996802 [DEBUG] switch_core_state_machine.c:86 modem/0/1xxxxxxxxxxxxx Standard DESTROY 2012-12-06 11:13:59.996802 [DEBUG] switch_core_state_machine.c:527 (modem/0/1xxxxxxxxxxxxx) State DESTROY going to sleep 2012-12-06 11:14:00.996881 [DEBUG] mod_spandsp_modem.c:1070 Modem /dev/FS0 [ONHOOK] - Hanging up 2012-12-06 11:14:00.996881 [DEBUG] mod_spandsp_modem.c:1076 Modem /dev/FS0 [ONHOOK] - Changing state to HANGUP 2012-12-06 11:14:00.996881 [DEBUG] mod_spandsp_modem.c:1095 Modem /dev/FS0 [HANGUP] - Changing state to ONHOOK 2012-12-06 11:14:19.676800 [DEBUG] mod_spandsp_modem.c:1070 Modem /dev/FS0 [ONHOOK] - Hanging up 2012-12-06 11:14:19.676800 [DEBUG] mod_spandsp_modem.c:1076 Modem /dev/FS0 [ONHOOK] - Changing state to HANGUP 2012-12-06 11:14:19.676800 [DEBUG] mod_spandsp_modem.c:1095 Modem /dev/FS0 [HANGUP] - Changing state to ONHOOK freeswitch@internal>