All pastes #978343 Raw Edit
Someone

public text v1 · immutable
·published 2008-04-09 14:17 UTC
FreeSWITCH>
FreeSWITCH>
FreeSWITCH>
FreeSWITCH>
FreeSWITCH>
FreeSWITCH>
FreeSWITCH>2008-04-09 10:16:41 [DEBUG] sofia.c:219 sofia_event_callback() event [nua_i_state] status [407][Proxy Authentication Required] session: n/a
2008-04-09 10:16:41 [NOTICE] switch_channel.c:531 switch_channel_set_name() New Channel sofia/default/620@dev.moctel.com [367b138f-624b-4e4d-81de-065454d69fba]
2008-04-09 10:16:41 [DEBUG] sofia.c:1595 sofia_handle_sip_i_state() Channel sofia/default/620@dev.moctel.com entering state [received]
2008-04-09 10:16:41 [DEBUG] sofia.c:1599 sofia_handle_sip_i_state() Remote SDP:
v=0
o=root 627535147 627535147 IN IP4 72.0.208.121
s=call
c=IN IP4 72.0.208.121
t=0 0
m=audio 63660 RTP/AVP 0 8 9 2 3 18 4 101
a=rtpmap:0 pcmu/8000
a=rtpmap:8 pcma/8000
a=rtpmap:9 g722/8000
a=rtpmap:2 g726-32/8000
a=rtpmap:3 gsm/8000
a=rtpmap:18 g729/8000
a=rtpmap:4 g723/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20

2008-04-09 10:16:41 [DEBUG] sofia_glue.c:2011 sofia_glue_negotiate_sdp() Audio Codec Compare [pcmu:0:8000]/[G722:9:8000]
2008-04-09 10:16:41 [DEBUG] switch_core_state_machine.c:364 switch_core_session_run() sofia/default/620@dev.moctel.com Running State Change CS_NEW
2008-04-09 10:16:41 [DEBUG] switch_core_state_machine.c:368 switch_core_session_run() (sofia/default/620@dev.moctel.com) State NEW
2008-04-09 10:16:41 [DEBUG] sofia_glue.c:2011 sofia_glue_negotiate_sdp() Audio Codec Compare [pcmu:0:8000]/[PCMU:0:8000]
2008-04-09 10:16:41 [DEBUG] sofia_glue.c:1333 sofia_glue_tech_set_codec() Set Codec sofia/default/620@dev.moctel.com PCMU/8000 20 ms 160 samples
2008-04-09 10:16:41 [DEBUG] sofia_glue.c:1975 sofia_glue_negotiate_sdp() Set 2833 dtmf payload to 101
2008-04-09 10:16:41 [DEBUG] sofia.c:1736 sofia_handle_sip_i_state() sofia/default/620@dev.moctel.com State Change CS_NEW -> CS_INIT
2008-04-09 10:16:41 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/default/620@dev.moctel.com [BREAK]
2008-04-09 10:16:41 [DEBUG] switch_core_state_machine.c:364 switch_core_session_run() sofia/default/620@dev.moctel.com Running State Change CS_INIT
2008-04-09 10:16:41 [DEBUG] switch_core_state_machine.c:413 switch_core_session_run() (sofia/default/620@dev.moctel.com) State INIT
2008-04-09 10:16:41 [DEBUG] mod_sofia.c:80 sofia_on_init() sofia/default/620@dev.moctel.com SOFIA INIT
2008-04-09 10:16:41 [DEBUG] mod_sofia.c:107 sofia_on_init() sofia/default/620@dev.moctel.com State Change CS_INIT -> CS_RING
2008-04-09 10:16:41 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/default/620@dev.moctel.com [BREAK]
2008-04-09 10:16:41 [DEBUG] switch_core_state_machine.c:413 switch_core_session_run() (sofia/default/620@dev.moctel.com) State INIT going to sleep
2008-04-09 10:16:41 [DEBUG] switch_core_state_machine.c:364 switch_core_session_run() sofia/default/620@dev.moctel.com Running State Change CS_RING
2008-04-09 10:16:41 [DEBUG] switch_core_state_machine.c:418 switch_core_session_run() (sofia/default/620@dev.moctel.com) State RING
2008-04-09 10:16:41 [DEBUG] mod_sofia.c:119 sofia_on_ring() sofia/default/620@dev.moctel.com SOFIA RING
2008-04-09 10:16:41 [DEBUG] switch_core_state_machine.c:65 switch_core_standard_on_ring() Standard RING sofia/default/620@dev.moctel.com
2008-04-09 10:16:41 [INFO] mod_dialplan_xml.c:223 dialplan_hunt() Processing John Doe->610@mt
2008-04-09 10:16:41 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions ${unroll_loops}(true) =~ /^true$/
2008-04-09 10:16:41 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions ${sip_looped_call}() =~ /^true$/
2008-04-09 10:16:41 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-04-09 10:16:41 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions ${strftime(%H%M)}(1016) =~ /^((09|1[0-7])[0-5][0-9]|1800)$/
2008-04-09 10:16:41 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(610) =~ /^886$/
2008-04-09 10:16:41 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-04-09 10:16:41 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(610) =~ /^\*\*(\d+)$/
2008-04-09 10:16:41 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-04-09 10:16:41 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(610) =~ /^870$/
2008-04-09 10:16:41 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-04-09 10:16:41 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions ${network_addr}(72.0.208.121) =~ /^$/
2008-04-09 10:16:41 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-04-09 10:16:41 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions ${numbering_plan}() =~ /^$/
2008-04-09 10:16:41 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions ${call_debug}(false) =~ /^true$/
2008-04-09 10:16:41 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-04-09 10:16:41 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions ${sip_has_crypto}() =~ /^(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)$/
2008-04-09 10:16:41 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-04-09 10:16:41 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(610) =~ /^88(.*)$|^\*0(.*)$/
2008-04-09 10:16:41 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-04-09 10:16:41 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(610) =~ /^\*69$|^869$/
2008-04-09 10:16:41 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-04-09 10:16:41 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(610) =~ /^80(\d{2})$/
2008-04-09 10:16:41 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-04-09 10:16:41 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(610) =~ /^81(\d{2})$/
2008-04-09 10:16:41 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-04-09 10:16:41 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(610) =~ /^82(\d{2})$/
2008-04-09 10:16:41 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-04-09 10:16:41 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(610) =~ /^83(\d{2})$/
2008-04-09 10:16:41 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-04-09 10:16:41 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(610) =~ /^8(10[01][0-9])$/
2008-04-09 10:16:41 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-04-09 10:16:41 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(610) =~ /^(6[0-9][0-9])$/
2008-04-09 10:16:41 [DEBUG] mod_dialplan_xml.c:107 parse_exten() test conditions destination_number(610) =~ /^620$/
2008-04-09 10:16:41 [DEBUG] mod_dialplan_xml.c:109 parse_exten() Regex mismatch
2008-04-09 10:16:41 [DEBUG] switch_core_state_machine.c:96 switch_core_standard_on_ring() sofia/default/620@dev.moctel.com State Change CS_RING -> CS_EXECUTE
2008-04-09 10:16:41 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/default/620@dev.moctel.com [BREAK]
2008-04-09 10:16:41 [DEBUG] switch_core_state_machine.c:418 switch_core_session_run() (sofia/default/620@dev.moctel.com) State RING going to sleep
2008-04-09 10:16:41 [DEBUG] switch_core_state_machine.c:364 switch_core_session_run() sofia/default/620@dev.moctel.com Running State Change CS_EXECUTE
2008-04-09 10:16:41 [DEBUG] switch_core_state_machine.c:428 switch_core_session_run() (sofia/default/620@dev.moctel.com) State EXECUTE
2008-04-09 10:16:41 [DEBUG] mod_sofia.c:156 sofia_on_execute() sofia/default/620@dev.moctel.com SOFIA EXECUTE
2008-04-09 10:16:41 [DEBUG] switch_core_state_machine.c:128 switch_core_standard_on_execute() Standard EXECUTE
2008-04-09 10:16:41 [DEBUG] switch_core_state_machine.c:139 switch_core_standard_on_execute() sofia/default/620@dev.moctel.com Execute set(open=true)
2008-04-09 10:16:41 [DEBUG] mod_dptools.c:493 set_function() SET [open]=[true]
2008-04-09 10:16:41 [DEBUG] switch_core_state_machine.c:139 switch_core_standard_on_execute() sofia/default/620@dev.moctel.com Execute set(use_profile=${cond(${acl(${network_addr} rfc1918)} == true ? nat : default)})
2008-04-09 10:16:41 [DEBUG] switch_core_session.c:984 switch_core_session_execute_application() sofia/default/620@dev.moctel.com Expanded String set(use_profile=default)
2008-04-09 10:16:41 [DEBUG] mod_dptools.c:493 set_function() SET [use_profile]=[default]
2008-04-09 10:16:41 [DEBUG] switch_core_state_machine.c:139 switch_core_standard_on_execute() sofia/default/620@dev.moctel.com Execute set_user(default@${domain})
2008-04-09 10:16:41 [DEBUG] switch_core_session.c:984 switch_core_session_execute_application() sofia/default/620@dev.moctel.com Expanded String set_user(default@64.235.217.38)
2008-04-09 10:16:41 [DEBUG] switch_core_state_machine.c:139 switch_core_standard_on_execute() sofia/default/620@dev.moctel.com Execute db(insert/spymap/${caller_id_number}/${uuid})
2008-04-09 10:16:41 [DEBUG] switch_core_session.c:984 switch_core_session_execute_application() sofia/default/620@dev.moctel.com Expanded String db(insert/spymap/620/367b138f-624b-4e4d-81de-065454d69fba)
2008-04-09 10:16:41 [DEBUG] switch_core_state_machine.c:139 switch_core_standard_on_execute() sofia/default/620@dev.moctel.com Execute db(insert/last_dial/${caller_id_number}/${destination_number})
2008-04-09 10:16:41 [DEBUG] switch_core_session.c:984 switch_core_session_execute_application() sofia/default/620@dev.moctel.com Expanded String db(insert/last_dial/620/610)
2008-04-09 10:16:41 [DEBUG] switch_core_state_machine.c:139 switch_core_standard_on_execute() sofia/default/620@dev.moctel.com Execute db(insert/last_dial/global/${uuid})
2008-04-09 10:16:41 [DEBUG] switch_core_session.c:984 switch_core_session_execute_application() sofia/default/620@dev.moctel.com Expanded String db(insert/last_dial/global/367b138f-624b-4e4d-81de-065454d69fba)
2008-04-09 10:16:41 [DEBUG] switch_core_state_machine.c:139 switch_core_standard_on_execute() sofia/default/620@dev.moctel.com Execute set(dialed_ext=610)
2008-04-09 10:16:41 [DEBUG] mod_dptools.c:493 set_function() SET [dialed_ext]=[610]
2008-04-09 10:16:41 [DEBUG] switch_core_state_machine.c:139 switch_core_standard_on_execute() sofia/default/620@dev.moctel.com Execute export(dialed_ext=610)
2008-04-09 10:16:41 [DEBUG] mod_dptools.c:626 export_function() EXPORT [dialed_ext]=[610]
2008-04-09 10:16:41 [DEBUG] switch_core_state_machine.c:139 switch_core_standard_on_execute() sofia/default/620@dev.moctel.com Execute info()
2008-04-09 10:16:41 [INFO] mod_dptools.c:685 info_function() CHANNEL_DATA:
Channel-State: [CS_EXECUTE]
Channel-State-Number: [4]
Channel-Name: [sofia/default/620@dev.moctel.com]
Unique-ID: [367b138f-624b-4e4d-81de-065454d69fba]
Call-Direction: [inbound]
Answer-State: [ringing]
Channel-Read-Codec-Name: [PCMU]
Channel-Read-Codec-Rate: [8000]
Channel-Write-Codec-Name: [PCMU]
Channel-Write-Codec-Rate: [8000]
Caller-Username: [620]
Caller-Dialplan: [XML]
Caller-Caller-ID-Name: [John Doe]
Caller-Caller-ID-Number: [620]
Caller-Network-Addr: [72.0.208.121]
Caller-Destination-Number: [610]
Caller-Unique-ID: [367b138f-624b-4e4d-81de-065454d69fba]
Caller-Source: [mod_sofia]
Caller-Context: [mt]
Caller-Channel-Name: [sofia/default/620@dev.moctel.com]
Caller-Profile-Index: [1]
Caller-Channel-Created-Time: [1207750601805634]
Caller-Channel-Answered-Time: [0]
Caller-Channel-Hangup-Time: [0]
Caller-Channel-Transfer-Time: [0]
Caller-Screen-Bit: [yes]
Caller-Privacy-Hide-Name: [no]
Caller-Privacy-Hide-Number: [no]
variable_sip_authorized: [true]
variable_sip_mailbox: [620]
variable_sip_auth_username: [620]
variable_sip_auth_realm: [dev.moctel.com]
variable_mailbox: [620]
variable_record_stereo: [true]
variable_sip-force-contact: [NDLB-connectile-dysfunction]
variable_accountcode: [1000]
variable_user_context: [mt]
variable_effective_caller_id_name: [John Does]
variable_effective_caller_id_number: [620]
variable_sip_from_user: [620]
variable_sip_from_uri: [620@dev.moctel.com]
variable_sip_from_host: [dev.moctel.com]
variable_sip_from_user_stripped: [620]
variable_sip_from_tag: [63lmjc7fx3]
variable_sofia_profile_name: [default]
variable_sofia_profile_domain_name: [default]
variable_sip_req_params: [user=phone]
variable_sip_req_user: [610]
variable_sip_req_uri: [610@dev.moctel.com]
variable_sip_req_host: [dev.moctel.com]
variable_sip_to_params: [user=phone]
variable_sip_to_user: [610]
variable_sip_to_uri: [610@dev.moctel.com]
variable_sip_to_host: [dev.moctel.com]
variable_sip_contact_params: [line=9awaxiyz]
variable_sip_contact_user: [620]
variable_sip_contact_port: [1043]
variable_sip_contact_uri: [620@72.0.208.121:1043]
variable_sip_contact_host: [72.0.208.121]
variable_channel_name: [sofia/default/620@dev.moctel.com]
variable_sip_call_id: [3c267ea9e1e7-jfv9801qv67j]
variable_sip_user_agent: [snom370/7.1.17]
variable_sip_via_host: [72.0.208.121]
variable_sip_via_port: [1043]
variable_sip_via_rport: [1043]
variable_max_forwards: [70]
variable_presence_id: [620@dev.moctel.com]
variable_sip_h_P-Key-Flags: [resolution="31x13", keys="4"]
variable_switch_r_sdp: [v=0
o=root 627535147 627535147 IN IP4 72.0.208.121
s=call
c=IN IP4 72.0.208.121
t=0 0
m=audio 63660 RTP/AVP 0 8 9 2 3 18 4 101
a=rtpmap:0 pcmu/8000
a=rtpmap:8 pcma/8000
a=rtpmap:9 g722/8000
a=rtpmap:2 g726-32/8000
a=rtpmap:3 gsm/8000
a=rtpmap:18 g729/8000
a=rtpmap:4 g723/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
]
variable_remote_media_ip: [72.0.208.121]
variable_remote_media_port: [63660]
variable_read_codec: [PCMU]
variable_read_rate: [8000]
variable_write_codec: [PCMU]
variable_write_rate: [8000]
variable_endpoint_disposition: [RECEIVED]
variable_open: [true]
variable_use_profile: [default]
variable_numbering_plan: [US]
variable_default_gateway: [asterlink.com]
variable_default_area_code: [918]
variable_user_name: [default]
variable_domain_name: [64.235.217.38]
variable_dialed_ext: [610]
variable_export_vars: [dialed_ext]


2008-04-09 10:16:41 [DEBUG] switch_core_state_machine.c:139 switch_core_standard_on_execute() sofia/default/620@dev.moctel.com Execute bind_meta_app(1 a a execute_extension::dx XML features)
2008-04-09 10:16:41 [INFO] switch_ivr_async.c:1357 switch_ivr_bind_dtmf_meta_session() Bound: 1 execute_extension::dx XML features
2008-04-09 10:16:41 [DEBUG] switch_core_state_machine.c:139 switch_core_standard_on_execute() sofia/default/620@dev.moctel.com Execute bind_meta_app(2 a a record_session::/opt/fs/recordings/${caller_id_number}.${strftime(%Y-%m-%d-%H-%M-%S)}.wav)
2008-04-09 10:16:41 [DEBUG] switch_core_session.c:984 switch_core_session_execute_application() sofia/default/620@dev.moctel.com Expanded String bind_meta_app(2 a a record_session::/opt/fs/recordings/620.2008-04-09-10-16-41.wav)
2008-04-09 10:16:41 [INFO] switch_ivr_async.c:1357 switch_ivr_bind_dtmf_meta_session() Bound: 2 record_session::/opt/fs/recordings/620.2008-04-09-10-16-41.wav
2008-04-09 10:16:41 [DEBUG] switch_core_state_machine.c:139 switch_core_standard_on_execute() sofia/default/620@dev.moctel.com Execute bind_meta_app(3 a a execute_extension::cf XML features)
2008-04-09 10:16:41 [INFO] switch_ivr_async.c:1357 switch_ivr_bind_dtmf_meta_session() Bound: 3 execute_extension::cf XML features
2008-04-09 10:16:41 [DEBUG] switch_core_state_machine.c:139 switch_core_standard_on_execute() sofia/default/620@dev.moctel.com Execute set(transfer_ringback=${us-ring})
2008-04-09 10:16:41 [DEBUG] switch_core_session.c:984 switch_core_session_execute_application() sofia/default/620@dev.moctel.com Expanded String set(transfer_ringback=%(2000, 4000, 440.0, 480.0))
2008-04-09 10:16:41 [DEBUG] mod_dptools.c:493 set_function() SET [transfer_ringback]=[%(2000, 4000, 440.0, 480.0)]
2008-04-09 10:16:41 [DEBUG] switch_core_state_machine.c:139 switch_core_standard_on_execute() sofia/default/620@dev.moctel.com Execute set(call_timeout=30)
2008-04-09 10:16:41 [DEBUG] mod_dptools.c:493 set_function() SET [call_timeout]=[30]
2008-04-09 10:16:41 [DEBUG] switch_core_state_machine.c:139 switch_core_standard_on_execute() sofia/default/620@dev.moctel.com Execute set(sip_exclude_contact=${network_addr})
2008-04-09 10:16:41 [DEBUG] switch_core_session.c:984 switch_core_session_execute_application() sofia/default/620@dev.moctel.com Expanded String set(sip_exclude_contact=72.0.208.121)
2008-04-09 10:16:41 [DEBUG] mod_dptools.c:493 set_function() SET [sip_exclude_contact]=[72.0.208.121]
2008-04-09 10:16:41 [DEBUG] switch_core_state_machine.c:139 switch_core_standard_on_execute() sofia/default/620@dev.moctel.com Execute set(hangup_after_bridge=true)
2008-04-09 10:16:41 [DEBUG] mod_dptools.c:493 set_function() SET [hangup_after_bridge]=[true]
2008-04-09 10:16:41 [DEBUG] switch_core_state_machine.c:139 switch_core_standard_on_execute() sofia/default/620@dev.moctel.com Execute set(continue_on_fail=true)
2008-04-09 10:16:41 [DEBUG] mod_dptools.c:493 set_function() SET [continue_on_fail]=[true]
2008-04-09 10:16:41 [DEBUG] switch_core_state_machine.c:139 switch_core_standard_on_execute() sofia/default/620@dev.moctel.com Execute db(insert/call_return/${dialed_ext}/${caller_id_number})
2008-04-09 10:16:41 [DEBUG] switch_core_session.c:984 switch_core_session_execute_application() sofia/default/620@dev.moctel.com Expanded String db(insert/call_return/610/620)
2008-04-09 10:16:41 [DEBUG] switch_core_state_machine.c:139 switch_core_standard_on_execute() sofia/default/620@dev.moctel.com Execute db(insert/last_dial_ext/${dialed_ext}/${uuid})
2008-04-09 10:16:41 [DEBUG] switch_core_session.c:984 switch_core_session_execute_application() sofia/default/620@dev.moctel.com Expanded String db(insert/last_dial_ext/610/367b138f-624b-4e4d-81de-065454d69fba)
2008-04-09 10:16:41 [DEBUG] switch_core_state_machine.c:139 switch_core_standard_on_execute() sofia/default/620@dev.moctel.com Execute bridge(user/${dialed_ext}@${sip_auth_realm})
2008-04-09 10:16:41 [DEBUG] switch_core_session.c:984 switch_core_session_execute_application() sofia/default/620@dev.moctel.com Expanded String bridge(user/610@dev.moctel.com)
2008-04-09 10:16:41 [WARNING] switch_ivr_originate.c:537 switch_ivr_originate() No origination URL specified!
2008-04-09 10:16:41 [DEBUG] switch_ivr_originate.c:1241 switch_ivr_originate() Originate Resulted in Error Cause: 27 [DESTINATION_OUT_OF_ORDER]
2008-04-09 10:16:41 [ERR] switch_ivr_originate.c:813 switch_ivr_originate() Cannot create outgoing channel of type [user] cause: [DESTINATION_OUT_OF_ORDER]
2008-04-09 10:16:41 [DEBUG] switch_ivr_originate.c:1241 switch_ivr_originate() Originate Resulted in Error Cause: 27 [DESTINATION_OUT_OF_ORDER]
2008-04-09 10:16:41 [INFO] mod_dptools.c:1536 audio_bridge_function() Originate Failed.  Cause: DESTINATION_OUT_OF_ORDER
2008-04-09 10:16:41 [DEBUG] mod_dptools.c:1557 audio_bridge_function() Continue on fail [true]:  Cause: DESTINATION_OUT_OF_ORDER
2008-04-09 10:16:41 [DEBUG] switch_core_state_machine.c:139 switch_core_standard_on_execute() sofia/default/620@dev.moctel.com Execute answer()
2008-04-09 10:16:41 [DEBUG] sofia_glue.c:1523 sofia_glue_activate_rtp() AUDIO RTP [sofia/default/620@dev.moctel.com] 64.235.217.38:26576->72.0.208.121:63660 codec: 0 ms: 20
2008-04-09 10:16:41 [DEBUG] switch_rtp.c:716 switch_rtp_create() Starting timer [soft] 160 bytes per 20000ms
2008-04-09 10:16:41 [DEBUG] mod_sofia.c:376 sofia_answer_channel() Local SDP sofia/default/620@dev.moctel.com:
v=0
o=FreeSWITCH 1207724025 1207724026 IN IP4 64.235.217.38
s=FreeSWITCH
c=IN IP4 64.235.217.38
t=0 0
a=sendrecv
m=audio 26576 RTP/AVP 0 101 13
a=rtpmap:0 pcmu/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=ptime:20

2008-04-09 10:16:41 [DEBUG] switch_core_session.c:383 switch_core_session_receive_message() Kill sofia/default/620@dev.moctel.com [BREAK]
2008-04-09 10:16:41 [NOTICE] mod_dptools.c:423 answer_function() Channel [sofia/default/620@dev.moctel.com] has been answered
2008-04-09 10:16:41 [DEBUG] sofia.c:1595 sofia_handle_sip_i_state() Channel sofia/default/620@dev.moctel.com entering state [completed]
2008-04-09 10:16:41 [DEBUG] switch_core_state_machine.c:139 switch_core_standard_on_execute() sofia/default/620@dev.moctel.com Execute sleep(1000)
2008-04-09 10:16:42 [DEBUG] sofia.c:1595 sofia_handle_sip_i_state() Channel sofia/default/620@dev.moctel.com entering state [ready]
2008-04-09 10:16:42 [DEBUG] switch_core_state_machine.c:139 switch_core_standard_on_execute() sofia/default/620@dev.moctel.com Execute voicemail(default ${sip_auth_realm} ${dialed_ext})
2008-04-09 10:16:42 [DEBUG] switch_core_session.c:984 switch_core_session_execute_application() sofia/default/620@dev.moctel.com Expanded String voicemail(default dev.moctel.com 610)
2008-04-09 10:16:42 [DEBUG] switch_ivr_play_say.c:115 switch_ivr_phrase_macro() No language specified - Using [en]
2008-04-09 10:16:42 [DEBUG] switch_ivr_play_say.c:259 switch_ivr_phrase_macro() Handle say:[610] (en:en)
2008-04-09 10:16:42 [DEBUG] mod_sndfile.c:170 sndfile_file_open() Opening File [/opt/fs/sounds/en/us/callie/digits/8000/6.wav] rate 8000hz
2008-04-09 10:16:42 [DEBUG] switch_ivr_play_say.c:868 switch_ivr_play_file() Codec Activated L16@8000hz 1 channels 20ms
2008-04-09 10:16:43 [DEBUG] switch_ivr_play_say.c:1135 switch_ivr_play_file() done playing file
2008-04-09 10:16:43 [DEBUG] mod_sndfile.c:170 sndfile_file_open() Opening File [/opt/fs/sounds/en/us/callie/digits/8000/1.wav] rate 8000hz
2008-04-09 10:16:43 [DEBUG] switch_ivr_play_say.c:868 switch_ivr_play_file() Codec Activated L16@8000hz 1 channels 20ms
2008-04-09 10:16:43 [DEBUG] switch_ivr_play_say.c:1135 switch_ivr_play_file() done playing file
2008-04-09 10:16:43 [DEBUG] mod_sndfile.c:170 sndfile_file_open() Opening File [/opt/fs/sounds/en/us/callie/digits/8000/0.wav] rate 8000hz
2008-04-09 10:16:43 [DEBUG] switch_ivr_play_say.c:868 switch_ivr_play_file() Codec Activated L16@8000hz 1 channels 20ms
2008-04-09 10:16:44 [DEBUG] switch_ivr_play_say.c:1135 switch_ivr_play_file() done playing file
2008-04-09 10:16:44 [DEBUG] switch_ivr_play_say.c:259 switch_ivr_phrase_macro() Handle play-file:[voicemail/vm-not_available.wav] (en:en)
2008-04-09 10:16:44 [ERR] mod_sndfile.c:164 sndfile_file_open() Error Opening File [/opt/fs/sounds/en/us/callie/voicemail/vm-not_available.wav] [System error : No such file or directory.]
2008-04-09 10:16:44 [DEBUG] switch_ivr_play_say.c:115 switch_ivr_phrase_macro() No language specified - Using [en]
2008-04-09 10:16:44 [DEBUG] switch_ivr_play_say.c:259 switch_ivr_phrase_macro() Handle play-file:[voicemail/vm-goodbye.wav] (en:en)
2008-04-09 10:16:44 [DEBUG] mod_sndfile.c:170 sndfile_file_open() Opening File [/opt/fs/sounds/en/us/callie/voicemail/8000/vm-goodbye.wav] rate 8000hz
2008-04-09 10:16:44 [DEBUG] switch_ivr_play_say.c:868 switch_ivr_play_file() Codec Activated L16@8000hz 1 channels 20ms